squid, использование опции debug_options или диагностика компонентов squid
Категорически Все
х приветствую у себя в блоге ) Во время базовой настройки squid, а так же аутентификации squid в AD довелось довольно часто и много траблшутить squid. В связи с этим, накопился некоторый объем сопутствующей и , возможно, полезной информации о диагностике squid, которой с Вами я спешу поделиться. Стоит отметить, что данная информация актуальна для squid версии 3.1. Возможно, для более старших версий что-то изменится… Как ни странно, в интернете я не смог найти более-менее наглядного материала по данному вопросу. Ни на английском, ни на русском. Страница документации squid debug_options так же не очень многословна, wiki – аналогично.
Диагностика squid
Начать я хочу не с секции debug_options, а с общих рекомендаций:
- Не забывайте о наличии общих команд Linux, позволяющих диагностировать работу сервиса (например netstat и ps)
- У squid3 имеется несколько ключей запуска, которые позволяют осуществить некоторый объем диагностики. Среди данных ключей под нашу задачу можно выделить:
- -k команда – послать команду работающему серверу, при этом команда – есть:
- reconfigure – посылка сигнала HUP – перечитать и использовать файл конфигурации (стоит использовать после parse). Стоит отметить, что при обработке команд reconfigure/rotate, Squid закрывает все соединения и открывает их заново, поэтому при большом количестве клиентов лучше этого не делать — создадите кому-то небольшой дискомфорт.
- check – проверить корректность работы squid (без сообщений – работает корректно); сигнал ZERO (полезно в процессе работы)
- parse – проверить синтаксис squid.conf
- -d – запуск squid3 для вывода отладочной информации на stderr
- -l facility – указать источник для записей в syslog
- -X – включить 9 уровень журналирования при разборе конфига (для использования с -k parse)
- -k команда – послать команду работающему серверу, при этом команда – есть:
- ну и не забывайте о наличии раздела настройки squid, в котором можно почерпнуть достаточно информации для исходной правильной конфигурации.
Опция debug_options в squid.conf
Если вышеприведенных инструментов будет недостаточно, можно заставить squid быть более разговорчивым с помощью опции debug_options в squid.conf. Давайте разберем синтаксис опции:
debug_options rotate=N section,verbosity [section,verbosity]…
Здесь, параметр rotate=N задает количество хранимых файлов cache.log при ротации. По-умолчанию, данное значение равно единице. Параметр section задает секцию (компонент squid), которая будет отправлять сообщения журналирования. На данном месте возможно использовать значение ALL (как говорит документация magic word “ALL”), которое обозначает все секции компоненты. Параметр verbosity указывает уровень критичности сообщений, записываемых в лог. Данный параметр может принимать следующие значения (некоторые не знал, как перевести):
| Уровень Verbosity |
Описание |
| 0 | Только сообщения критичного/смертельного (critical or fatal) уровня. |
| 1 | Уровни Warnings и important. |
| 2 | На данном уровне будут логироваться сообщения the minor problems, recovery, and regular high-level actions. |
| 3-5 | Сообщения, уровня пользовательской детализации. |
| 6-9 | Уровень выше 5го очень “многословен” ) Выводятся в лог отдельные события, сигналы, обращения к памяти/файлам. |
Могу сказать, что в реальной жизни редко приходится использовать уровень выше 5го.
Параметр section в debug_options
Давайте приступим к самому интересному. Ниже я приведу список значений поля section для опции debug_options, описание каждого значения и пример лога, который формируется при использовании секции.
section — и 00
— CGI Cache Manager
— External DISKD process implementation.
— Refcount allocator
— Unlink Daemon
— WWW Client
00 Announcement Server
00 Client Database
00 DNS Resolver Daemon
00 Debug Routines
00 Hash Tables
00 UFS Store Dump Tool
— и 00 – ХЗ, активности не замечено
section 01
01 Main Loop
01 Startup and Main Loop
01 – хорошо просматриваются стартовый парсинг системных конфигов, таких как /etc/hosts, resolv.conf и др.
section 02 и 03
02 Unlink Daemon
03 Configuration File Parsing
03 Configuration Settings
03 – ХЗ, активности не замечено
section 04 Error Generation
04 – дебаг формирования страниц ошибок squid (хорошо видна подмена переменных, используемых в HTML коде в страниц ошибок)
section 05
05 Comm
05 Socket Functions
05 – Довольно не наглядный лог, не о чем не сказало. Куча инфы о сокетах в виде:
The AsyncCall comm_close_complete constructed, this=0x95b6b78 [call3644] или commSetSelect(FD 12,type=1,handler=0,client_data=0,timeout=0)
section 06 Disk I/O Routines
06 – статистика обращений к файлам на диске, в виде
2012/03/23 22:52:23.483| file_open: FD 7 2012/03/23 22:52:23.483| file_close: FD 7 really closing
или
2012/03/23 22:53:59.443| file_open: FD 66 2012/03/23 22:53:59.443| diskHandleWrite: FD 66 2012/03/23 22:53:59.443| diskHandleWrite: FD 66 2012/03/23 22:53:59.443| diskHandleWrite: FD 66 writing 111 bytes 2012/03/23 22:53:59.444| diskHandleWrite: FD 66 len = 111 2012/03/23 22:53:59.444| diskHandleWrite: FD 66 2012/03/23 22:53:59.444| diskHandleWrite: FD 66 writing 4096 bytes 2012/03/23 22:53:59.444| diskHandleWrite: FD 66 len = 4096 2012/03/23 22:53:59.447| diskHandleWrite: FD 66 2012/03/23 22:53:59.447| diskHandleWrite: FD 66 writing 1054 bytes 2012/03/23 22:53:59.447| diskHandleWrite: FD 66 writing 1054 bytes 2012/03/23 22:53:59.447| diskHandleWrite: FD 66 len = 1054 2012/03/23 22:53:59.447| diskHandleWrite: FD 66 len = 1054 2012/03/23 22:53:59.448| file_close: FD 66 really closing
section 07 Multicast
07 – по логике – должен писать что-то о мультикасте, но нет возможности протестировать
section 08 Swap File Bitmap
08 – хз
section 09 File Transfer Protocol (FTP)
09 – хорошо диагностирует FTP (если он у Вас разрешен к проксированию), достаточно уровня журнала 2-3. Все наглядно и понятно.
section 10 Gopher
гофером не пользуюсь, а вы? )
section 10 Hypertext Transfer Protocol (HTTP)
11 – записывает процесс обмена клиентом с удаленным сервером через сквид, при этом, при 9 уровне пишет все, вплоть до развернутых HTTP-ответов. Пример запроса https://www.k-max.name/favicon.ico на 3 уровне лога:
2012/03/23 23:13:05.761| httpStart: "GET https://www.k-max.name/favicon.ico" 2012/03/23 23:13:05.804| ctx: enter level 0: 'https://www.k-max.name/favicon.ico' 2012/03/23 23:13:05.804| processReplyHeader: key '71A136F1A710CA94CD009859AD58D03D' 2012/03/23 23:13:05.804| ctx: exit level 0 2012/03/23 23:13:05.804| ctx: enter level 0: 'https://www.k-max.name/favicon.ico' 2012/03/23 23:13:05.804| haveParsedReplyHeaders: HTTP CODE: 304 2012/03/23 23:13:05.804| haveParsedReplyHeaders: HTTP CODE: 304 2012/03/23 23:13:05.804| ctx: exit level 0 2012/03/23 23:13:05.804| persistentConnStatus: FD 11 eof=0 2012/03/23 23:13:05.804| Server.cc(225) quitIfAllDone: transaction done
Запрос того же https://www.k-max.name/favicon.ico на 9 уровне:
2012/03/23 23:14:04.861| httpStart: "GET https://www.k-max.name/favicon.ico" 2012/03/23 23:14:04.861| http.cc(83) HttpStateData: HttpStateData 0xa5b8a78 created 2012/03/23 23:14:04.861| httpSendRequest: FD 11, request 0xa4e1a88, this 0xa5b8a78. 2012/03/23 23:14:04.861| The AsyncCall HttpStateData::httpTimeout constructed, this=0xa783830 [call16817] 2012/03/23 23:14:04.861| http.cc(1392) maybeReadVirginBody: may read up to 2047 bytes from FD 11 2012/03/23 23:14:04.861| The AsyncCall HttpStateData::readReply constructed, this=0x94b0fb0 [call16818] 2012/03/23 23:14:04.861| The AsyncCall HttpStateData::SendComplete constructed, this=0xa524a20 [call16819] 2012/03/23 23:14:04.861| The AsyncCall HttpStateData::readReply constructed, this=0x94b0fb0 [call16818] 2012/03/23 23:14:04.861| The AsyncCall HttpStateData::SendComplete constructed, this=0xa524a20 [call16819] 2012/03/23 23:14:04.861| decideIfWeDoRanges: range specs: 0, cachable: 1; we_do_ranges: 0 2012/03/23 23:14:04.861| httpBuildRequestHeader: Host: www.k-max.name 2012/03/23 23:14:04.861| httpBuildRequestHeader: Host: www.k-max.name 2012/03/23 23:14:04.862| httpBuildRequestHeader: User-Agent: Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20120302 Firefox/10.0.2 2012/03/23 23:14:04.862| httpBuildRequestHeader: User-Agent: Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20120302 Firefox/10.0.2 2012/03/23 23:14:04.862| httpBuildRequestHeader: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 2012/03/23 23:14:04.862| httpBuildRequestHeader: Accept-Language: ru-ru,ru;q=0.8,en-us;q=0.5,en;q=0.3 2012/03/23 23:14:04.862| httpBuildRequestHeader: Accept-Encoding: gzip, deflate 2012/03/23 23:14:04.862| httpBuildRequestHeader: Proxy-Connection: keep-alive 2012/03/23 23:14:04.862| httpBuildRequestHeader: If-Modified-Since: Fri, 31 Dec 2010 16:47:34 GMT 2012/03/23 23:14:04.862| httpBuildRequestHeader: If-None-Match: "a319b-7a2-8f181580" 2012/03/23 23:14:04.862| httpBuildRequestHeader: If-None-Match: "a319b-7a2-8f181580" 2012/03/23 23:14:04.862| httpBuildRequestHeader: Cache-Control: max-age=0 2012/03/23 23:14:04.862| httpBuildRequestHeader: Cache-Control: max-age=0 2012/03/23 23:14:04.862| httpSendRequest: FD 11: GET /favicon.ico HTTP/1.1 Host: www.k-max.name User-Agent: Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20120302 Firefox/10.0.2 Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 Accept-Language: ru-ru,ru;q=0.8,en-us;q=0.5,en;q=0.3 Accept-Encoding: gzip, deflate If-Modified-Since: Fri, 31 Dec 2010 16:47:34 GMT If-None-Match: "a319b-7a2-8f181580" Via: 1.1 gw (squid/3.1.6) X-Forwarded-For: unknown Cache-Control: max-age=0 Connection: keep-alive 2012/03/23 23:14:04.862| comm.cc(165) will call HttpStateData::SendComplete(FD 11, data=0xa5b8a78) [call16819] 2012/03/23 23:14:04.862| comm.cc(165) will call HttpStateData::SendComplete(FD 11, data=0xa5b8a78) [call16819] 2012/03/23 23:14:04.862| entering HttpStateData::SendComplete(FD 11, data=0xa5b8a78) 2012/03/23 23:14:04.862| AsyncCall.cc(32) make: make call HttpStateData::SendComplete [call16819] 2012/03/23 23:14:04.862| HttpStateData status in: [ job773] 2012/03/23 23:14:04.862| HttpStateData status in: [ job773] 2012/03/23 23:14:04.862| httpSendComplete: FD 11: size 483: errflag 0. 2012/03/23 23:14:04.862| httpSendComplete: FD 11: size 483: errflag 0. 2012/03/23 23:14:04.862| The AsyncCall HttpStateData::httpTimeout constructed, this=0x94fd3e0 [call16820] 2012/03/23 23:14:04.862| HttpStateData status out: [ job773] 2012/03/23 23:14:04.863| leaving HttpStateData::SendComplete(FD 11, data=0xa5b8a78) 2012/03/23 23:14:04.903| comm.cc(165) will call HttpStateData::readReply(FD 11, data=0xa5b8a78, size=318, buf=0xa47b688) [call16818] 2012/03/23 23:14:04.903| entering HttpStateData::readReply(FD 11, data=0xa5b8a78, size=318, buf=0xa47b688) 2012/03/23 23:14:04.903| AsyncCall.cc(32) make: make call HttpStateData::readReply [call16818] 2012/03/23 23:14:04.903| AsyncCall.cc(32) make: make call HttpStateData::readReply [call16818] 2012/03/23 23:14:04.903| HttpStateData status in: [ job773] 2012/03/23 23:14:04.903| HttpStateData status in: [ job773] 2012/03/23 23:14:04.903| httpReadReply: FD 11: len 318. 2012/03/23 23:14:04.904| ctx: enter level 0: 'https://www.k-max.name/favicon.ico' 2012/03/23 23:14:04.904| processReplyHeader: key '2EFDBB686248DB35939D740C70B8AD65' 2012/03/23 23:14:04.904| GOT HTTP REPLY HDR: --------- HTTP/1.1 304 Not Modified Date: Fri, 23 Mar 2012 19:14:04 GMT Server: Apache/2.0.63-lk.d (Unix) mod_ssl/2.0.63-lk.d OpenSSL/0.9.8o mod_dp20/0.99.2 mod_python/3.3.1 Python/2.6.5 mod_ruby/1.2.6 Ruby/1.8.7(2010-08-16) mod_wsgi/3.3 Connection: Keep-Alive Keep-Alive: timeout=30, max=128 ETag: "a319b-7a2-8f181580" ---------- 2012/03/23 23:14:04.904| Server.cc(136) setVirginReply: 0xa5b8a78 setting virgin reply to 0xa694218 2012/03/23 23:14:04.904| Server.cc(136) setVirginReply: 0xa5b8a78 setting virgin reply to 0xa694218 2012/03/23 23:14:04.904| ctx: exit level 0 2012/03/23 23:14:04.904| Server.cc(819) adaptOrFinalizeReply: adaptationAccessCheckPending=0 2012/03/23 23:14:04.904| Serv delay_pools 1 per.cc(819) adaptOrFinalizeReply: adaptationAccessCheckPending=0 2012/03/23 23:14:04.904| Server.cc(153) setFinalReply: 0xa5b8a78 setting final reply to 0xa694218 2012/03/23 23:14:04.904| ctx: enter level 0: 'https://www.k-max.name/favicon.ico' 2012/03/23 23:14:04.904| haveParsedReplyHeaders: HTTP CODE: 304 2012/03/23 23:14:04.904| ctx: exit level 0 2012/03/23 23:14:04.904| http.cc(1299) processReplyBody: adaptationAccessCheckPending=0 2012/03/23 23:14:04.904| persistentConnStatus: FD 11 eof=0 2012/03/23 23:14:04.904| persistentConnStatus: content_length=-1 2012/03/23 23:14:04.904| persistentConnStatus: content_length=-1 2012/03/23 23:14:04.904| persistentConnStatus: flags.headers_parsed=1 2012/03/23 23:14:04.904| persistentConnStatus: clen=0 2012/03/23 23:14:04.904| processReplyBody: COMPLETE_PERSISTENT_MSG 2012/03/23 23:14:04.904| processReplyBody: COMPLETE_PERSISTENT_MSG 2012/03/23 23:14:04.904| Server.cc(169) serverComplete: serverComplete 0xa5b8a78 2012/03/23 23:14:04.904| Server.cc(194) serverComplete2: serverComplete2 0xa5b8a78 2012/03/23 23:14:04.905| Server.cc(234) completeForwarding: completing forwarding for 0xa5bd180*2 2012/03/23 23:14:04.905| Server.cc(225) quitIfAllDone: transaction done 2012/03/23 23:14:04.905| Server.cc(556) cleanAdaptation: cleaning ICAP; ACL: 0 2012/03/23 23:14:04.905| http.cc(163) ~HttpStateData: HttpStateData 0xa5b8a78 destroyed; FD -1 2012/03/23 23:14:04.905| leaving HttpStateData::readReply(FD 11, data=0xa5b8a78, size=318, buf=0xa47b688) 2012/03/23 23:14:04.905| leaving HttpStateData::readReply(FD 11, data=0xa5b8a78, size=318, buf=0xa47b688)
section 12 Internet Cache Protocol (ICP)
не использую ICP протестить не могу 
section 12 High Level Memory Pool Management
13 – по всей видимости какая-то информация о памяти, но активности не выявлено
section 12
14 IP Cache
14 IP Storage and Handling
14 – пишется процесс получения/кэширования/очистки кэша IP в виде
2012/03/23 23:19:38.926| ipcache_nbgethostbyname: Name 'mc.yandex.ru'. 2012/03/23 23:19:38.926| ipcache_nbgethostbyname: HIT for 'mc.yandex.ru' 2012/03/23 23:19:38.926| ipcache_nbgethostbyname: HIT for 'mc.yandex.ru' 2012/03/23 23:19:38.926| connecting to: 87.250.250.119:80 2012/03/23 23:19:38.926| connecting to: 87.250.250.119:80 2012/03/23 23:19:43.810| ipcache_purgelru: removed 0 entries
section 15 Neighbor Routines
15 – видимо какая-то информация о соседских кэшах, нет возможности протетсить
section 16 Cache Manager Objects
16 – какая-то неразборчивая инфа о диагностике кэш-менеджера
section 17 Request Forwarding
17 – должно отображать какие-то перенаправления, но я не понял, какие (возможно, если используется несколько интерфейсов, или каскадирование кэшей). Зато хорошо видно, какие страницы запрашиваются и видно исходящий адрес/интерфейс для каждой запрашиваемой страницы
section 18 Cache Manager Statistics
18 – тоже что-то связанное с кэш менеджером – актвиности не видно
section 19 Store Memory Primitives
19 – пишет непонятную инфу о использовании памяти в виде
2012/03/23 23:33:23.513| mem_hdr::write: [335,337) object end 335 2012/03/23 23:33:23.513| mem_hdr::write: [335,337) object end 335 2012/03/23 23:33:23.513| memWrite: offset -4 len 2 2012/03/23 23:33:23.513| memWrite: offset -4 len 2
так же, на 4 уровне выводит сообщения
2012/03/23 23:34:35.814| MemObject::isContiguous: Returning true
на сколько понял, если объект отдается из кэша
section 20
20 Storage Manager
20 Storage Manager Heap-based replacement
20 Storage Manager Logging Functions
20 Storage Manager MD5 Cache Keys
20 Storage Manager Swapfile Metadata
20 Storage Manager Swapfile Unpacker
20 Storage Manager Swapin Functions
20 Storage Manager Swapout Functions
20 Store Rebuild Routines
20 Swap Dir base object
20 – пишет какую-то кашу о работе с запрошенными из браузера объектами и взаимодействие этих объектов с памятью/кэшем на диске
section 21
21 Integer functions
21 Misc Functions
21 Time Functions
21 – непонятная инфа. Есть кое-что о присваиваемых PID для squid в виде:
2012/03/23 23:43:10.268| enter_suid: PID 14367 taking root priveleges 2012/03/23 23:43:10.268| leave_suid: PID 14367 called 2012/03/23 23:43:10.268| leave_suid: PID 14367 giving up root, becoming 'proxy' 2012/03/23 23:43:10.268| leave_suid: PID 14367 giving up root, becoming 'proxy' 2012/03/23 23:43:10.268| Accepting HTTP connections at 127.0.0.1:3129, FD 46.
section 22 Refresh Calculation
22 – пишет информацию о обновлении объектов в кэше в виде:
2012/03/23 23:49:12.655| ctx: enter level 0: 'http://www.mmnt.ru/get?st=123&in=f' 2012/03/23 23:49:12.700| refreshCheck: 'http://www.mmnt.ru/get?st=123&in=f' 2012/03/23 23:49:12.700| STALE: age 60 > max 0 2012/03/23 23:49:12.700| Staleness = 60 2012/03/23 23:49:12.700| refreshCheck: Matched '(/cgi-bin/|\?) 0 0%% 0' 2012/03/23 23:49:12.700| Staleness = 60 2012/03/23 23:49:12.700| refreshCheck: Matched '(/cgi-bin/|\?) 0 0%% 0' 2012/03/23 23:49:12.700| refreshCheck: age = 60 2012/03/23 23:49:12.700| check_time: Fri, 23 Mar 2012 19:50:12 GMT 2012/03/23 23:49:12.700| entry->timestamp: Fri, 23 Mar 2012 19:49:12 GMT 2012/03/23 23:49:12.700| refreshIsCachable() returned non-cacheable..
удобно для отработки директив refresh_pattern. Довольно наглядно уже на 4 уровне лога
section 23
23 URL Parsing
23 URL Scheme parsing
23 – хорошо отображает как сквид “разбирает” ссылки по компонентам, на примере
2012/03/23 23:52:22.857| urlParse: Split URL 'https://www.k-max.name/favicon.ico' into proto='http', host='www.k-max.name', port='80', path='/favicon.ico'
section 25
25 MIME Parsing and Internal Icons
25 MiME Header Parsing
25 – отображает MIME типы проходящего через сквид контента (могу предположить, что берет из /etc/mime.types). При рестарте куча строк вида:
.... 2012/03/23 23:56:33.769| mimeInit: added '\.gif$ image/gif anthony-image.gif - image +download' 2012/03/23 23:56:33.769| mimeInit: added '\.mime$ www/mime anthony-text.gif - ascii +download' ....
Думаю, что можно использовать для диагностики ACL req_mime_type или rep_mime_type для блокировки скачивания файлов по типу MIME.
section 26 Secure Sockets Layer Proxy
26 – пишет в лог какое-то месиво при использовании https (3 уровень от 9 не сильно отличается)
section 27 Cache Announcer
27 – ХЗ. Не обнаружено активности даже на 9 уровне
section 28 Access Control
28 – вот эта секция – основа для дебага acl и http_access. На 3 уровне лога уже вполне достаточная активность!
section 29
29 Authenticator
29 NTLM Authenticator
29 Negotiate Authenticator
29 – дебаг аутентификационной информации (малоиннформативный )
section 30 и 31
30 Ident (RFC 931)
31 Hypertext Caching Protocol
31 – ХЗ, активности не замечено
section 32 Asynchronous Disk I/O
32 – что то связано с IO, но малоинформативно
section 33 Client-side Routines
33 – отображает работу клиентского браузера (из всей каши, имхо интересны только содержимое HTTP-запросов, которое видно уже на 3 уровне дебага)
2012/03/24 00:48:34.431| parseHttpRequest: req_hdr = {Host: www.k-max.name
User-Agent: Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20120302 Firefox/10.0.2
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: ru-ru,ru;q=0.8,en-us;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Proxy-Connection: keep-alive
Cookie: __utma=238845466.1148771502.1332530869.1332530869.1332535340.2; __utmc=238845466; __utmz=238845466.1332530869.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); _ym_visorc=w; __utmb=238845466.2.10.1332535340
If-Modified-Since: Fri, 31 Dec 2010 16:47:34 GMT
If-None-Match: "a319b-7a2-8f181580"
Cache-Control: max-age=0
}
2012/03/24 00:48:34.431| parseHttpRequest: end = {
}
2012/03/24 00:48:34.431| parseHttpRequest: prefix_sz = 674, req_line_sz = 48
2012/03/24 00:48:34.432| clientSetKeepaliveFlag: http_ver = 1.1
2012/03/24 00:48:34.432| clientSetKeepaliveFlag: method = GET
2012/03/24 00:48:34.507| ClientSocketContext::keepaliveNextRequest: FD 106
2012/03/24 00:48:34.507| httpRequestFree: https://www.k-max.name/favicon.ico
section 34 Dnsserver interface
34 – ХЗ….
section 35 FQDN Cache
35 – отображает неинтересную статистику кэша fqdn DNS имен
section 37 ICMP Routines
37 – ХЗ. ICMP не смог помониторить – тишина. Может используется при каскадировании кэшей…
section 38 Network Measurement Database
38 – ХЗ. никакой активности…
section 39
39 Cache Array Routing Protocol
39 Peer source hash based selection
39 Peer user hash based selection
39 – ХЗ. Видимо для работы с соседними кэшами, может быть )
section 40
40 Referer Logging
40 User-Agent Logging
40 – ХЗ. По идее- должен быть лог реферреров и юзер-агентов браузера тишина
section 41 Event Processing
41 – пишется какая-то каша событий
section 42 и 43
42 ICMP Pinger program
43 AIOPS
43 Windows AIOPS
42,43 – ХЗ. Какой-то пингер и AIOPS
section 44 Peer Selection Algorithm
44 – используется при применении каскадирования кэшей, протестировать не удалось (
section 45 Callback Data Registry
45 – ХЗ… несусветная каша )
section 46 Access Log
46 – ХЗ. тишина
section 47
47 Store COSS Directory Routines
47 Store Directory Routines
47 – статистика работы с кэшем, для чего может быть использована- не знаю (
section 48 Persistent Connections
48 – какая-то статистика соединений в виде:
2012/03/24 01:10:52.974| PconnPool::push: pushed FD 28 for mc.yandex.ru:80
2012/03/24 01:10:52.981| PconnPool::key(kiks.yandex.ru,80,(no domain),[::]is {kiks.yandex.ru:80}
2012/03/24 01:10:52.981| PconnPool::push: new IdleConnList for {kiks.yandex.ru:80}
2012/03/24 01:10:52.981| PconnPool::push: pushed FD 30 for kiks.yandex.ru:80
section 49
49 SNMP Interface
49 SNMP support
49 – статистика протокола SNMP, к сожалению, не использую. Думаю, что будет актуально для диагностики директив snmp_access, snmp_incoming_address, snmp_outgoing_address, snmp_port
section 50 Log file handling
50 – статистика вида:
2012/03/24 01:13:21.746| comm_openex: Attempt open socket for: 0.0.0.0 2012/03/24 01:13:21.746| comm_openex: Opened socket FD 10 : family=2, type=1, protocol=6 2012/03/24 01:13:21.747| commBind: bind socket FD 10 to 0.0.0.0 2012/03/24 01:13:24.690| comm_old_accept: FD 67: (11) Resource temporarily unavailable 2012/03/24 01:13:24.750| comm_old_accept: FD 67: (11) Resource temporarily unavailable 2012/03/24 01:13:24.760| comm_openex: Attempt open socket for: 0.0.0.0 2012/03/24 01:13:24.761| comm_openex: Opened socket FD 21 : family=2, type=1, protocol=6 2012/03/24 01:13:24.761| commBind: bind socket FD 21 to 0.0.0.0 2012/03/24 01:13:24.761| comm_udp_sendto: Attempt to send UDP packet to 127.0.0.1:53 using FD 8 using Port 54923
section 51 Filedescriptor Functions
51 – отображает какую-то статистику по сокетам при запуске демона:
2012/03/24 01:16:02.704| helperOpenServers: Starting 15/15 'squid_kerb_auth' processes 2012/03/24 01:16:02.705| fd_open() FD 9 IPC UNIX STREAM Parent 2012/03/24 01:16:02.705| fd_open() FD 10 IPC UNIX STREAM Parent 2012/03/24 01:16:02.711| fd_open() FD 11 IPC UNIX STREAM Parent 2012/03/24 01:16:02.711| fd_open() FD 12 IPC UNIX STREAM Parent ....
и по соединениям:
2012/03/24 01:38:28.337| fd_open() FD 61 mailstatic.yandex.net:443 2012/03/24 01:38:28.340| fd_open() FD 62 mailstatic.yandex.net:443 2012/03/24 01:38:28.602| fd_open() FD 63 HTTP Request 2012/03/24 01:38:28.616| fd_open() FD 64 mc.yandex.ru:443 2012/03/24 01:38:33.023| fd_close FD 28 yandex.st:443 2012/03/24 01:38:33.023| fd_close FD 22 Reading next request
section 52 URN Parsing
52 – дебаггинг URN (не использую – не могу проверить)
section 53
53 AS Number handling
53 Radix Tree data structure implementation
53 – ХЗ… Тишина
section 54
54 Interprocess Communication
54 Windows Interprocess Communication
54 – статистика работы с сокетами IPC при запуске…
section 55 HTTP Header
55 – разбор сквидом http запроса от браузера и http ответа от сервера (человекопонятно становиться на 7 уровне, очень подробно – на 9) – ДИАГНОСТИКА запросов/ответов
section 56 HTTP Message Body
56 – тишина
section 57 HTTP Status-line
57 – статистика http статусов
section 58 HTTP Reply (Response)
58 – статистика http ответов с развернутым содержимым
section 59 и 60
59 auto-growing Memory Buffer with printf
60 Packer: A uniform interface to store-like modules
ХЗ, тишина
section 61 Redirector
61 – наверно, статистика редиректора (не использую…)
section 62-73
62 Generic Histogram
63 Low Level Memory Pool Management
64 HTTP Range Header
65 HTTP Cache Control Header
66 HTTP Header Tools
67 String
68 HTTP Content-Range Header
69 HTTP Header: Extension Field
70 Cache Digest
71 Store Digest Manager
72 Peer Digest Routines
73 HTTP Request
Заставить работать данные секции мне не удалось.
section 74 HTTP Message
74 – вывод http сообщений с содержимым (важная инфа для дебага), вид при запросе https://www.k-max.name/favicon.ico:
2012/03/24 02:08:21.099| httpParserParseReqLine: parsing GET https://www.k-max.name/favicon.ico HTTP/1.1 Accept: */* Accept-Language: ru User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729) Accept-Encoding: gzip, deflate Proxy-Connection: Keep-Alive Host: www.k-max.name Pragma: no-cache 2012/03/24 02:08:21.099| Parser: retval 1: from 0->47: method 0->2; url 4->36; version 38->46 (1/1) 2012/03/24 02:08:21.116| httpParseInit: Request buffer is GET https://www.k-max.name/favicon.ico HTTP/1.1 Accept: */* Accept-Language: ru User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729) Accept-Encoding: gzip, deflate Proxy-Connection: Keep-Alive Proxy-Authorization: Negotiate TlRMTVNTUAABAAAAB4IIogAAAAAAAAAAAAAAAAAAAAAFASgKAAAADw== Pragma: no-cache Host: www.k-max.name
section 75 WHOIS protocol
75 – видимо должны быть логи при проксировании whois протокола
section 76 Internal Squid Object handling
76 – ХЗ, тишина
section 77 Delay Pools
77 – К сожалению, проводил данные тесты до написания статьи Delay Pools, поэтому лога пока нет
section 78
78 DNS lookups
78 DNS lookups; interacts with lib/rfc1035.c
78 – статистика работы DNS в виде:
2012/03/24 02:13:32.225| idnsALookup: buf is 24 bytes for who.is, id = 0x6d86 2012/03/24 02:13:32.230| idnsRead: starting with FD 8 2012/03/24 02:13:32.230| idnsRead: FD 8: received 117 bytes from 127.0.0.1:53 2012/03/24 02:13:32.230| idnsGrokReply: ID 0x6d86, 1 answers 2012/03/24 02:13:32.230| dns_internal.cc(1115) idnsGrokReply: Sending 1 DNS results to caller. 2012/03/24 02:13:32.643| idnsRead: starting with FD 8 2012/03/24 02:13:32.643| idnsRead: FD 8: received 506 bytes from 127.0.0.1:53
section 79
79 Disk IO Routines
79 Squid-side DISKD I/O functions.
79 Squid-side Disk I/O functions.
79 Storage Manager COSS Interface
79 Storage Manager UFS Interface
79 – статистика работы с кэшем
section 80 WCCP Support
80 – видимо статистика WCPP (не использую WCPP, пока… )) )
section 81
81 CPU Profiling Routines
81 Store HEAP Removal Policies
81 aio_xxx() POSIX emulation on Windows
81 – Думаю, что используется для вендового squid
section 82 External ACL
82 – статистика внешних ACL
section 83 SSL accelerator support
83 – ХЗ, непонятные строки вида:
2012/03/24 02:20:21.422| AccessCheck.cc(30) Start: adaptation off, skipping 2012/03/24 02:20:21.422| client_side_request.cc(1306) doCallouts: Doing calloutContext->clientAccessCheck2() 2012/03/24 02:20:21.422| client_side_request.cc(1313) doCallouts: Doing clientInterpretRequestHeaders() 2012/03/24 02:20:21.422| client_side_request.cc(1348) doCallouts: calling processRequest()
section 84 Helper process maintenance
84 – включение дебага хелперов аутентификации
section 85 Client-side Request Routines
85 – отличный дебаг http_access и acl – кратко и понятно
section 86
86 ESI Expressions
86 ESI processing
86 – ESI не использую, лог получить возможности нет
section 87 Client-side Stream routines.
87 – непонятная каша виде:
2012/03/24 02:26:44.506| clientStreamInsertHead: Inserted node 0xa8d2a78 with data 0xa8d17cc after head 2012/03/24 02:26:44.507| clientStreamRead: Calling 1 with cbdata 0xa8d2928 from node 0xa8d2a78 2012/03/24 02:26:44.581| clientStreamCallback: Calling 1 with cbdata 0xa8d17cc from node 0xa8d2a28 2012/03/24 02:26:44.581| clientStreamDetach: Detaching node 0xa8d2a78 2012/03/24 02:26:44.581| Freeing clientStreamNode 0xa8d2a78 2012/03/24 02:26:44.581| clientStreamAbort: Aborting stream with tail 0xa8d2a28 2012/03/24 02:26:44.581| clientStreamDetach: Detaching node 0xa8d2a28 2012/03/24 02:26:44.581| clientStreamDetach: Calling 1 with cbdata 0xa8d2928 2012/03/24 02:26:44.581| Freeing clientStreamNode 0xa8d2a28 2012/03/24 02:26:44.581| Freeing clientStreamNode 0xa8d2a28
section 88 Client-side Reply Routines
88 – отличный дебаг http_access и acl – кратко и понятно
section 89 NAT / IP Interception
89 – очень полезная секция при дебаге прозрачного прокси.
section 90
90 HTTP Cache Control Header
90 Storage Manager Client-Side Interface
90 – ХЗ. статистика работы с кэшем, вида:
2012/03/24 02:30:14.776| store_client::copy: 04AFD5B6421D00FDA0A0720BDD377B00, from 0, for length 4096, cb 1, cbdata 0xa975af0 2012/03/24 02:30:14.776| storeClientCopy2: 04AFD5B6421D00FDA0A0720BDD377B00 2012/03/24 02:30:14.776| store_client::doCopy: Waiting for more 2012/03/24 02:30:14.857| InvokeHandlers: 04AFD5B6421D00FDA0A0720BDD377B00 2012/03/24 02:30:14.857| StoreEntry::InvokeHandlers: checking client #0 2012/03/24 02:30:14.857| storeClientCopy2: returning because ENTRY_FWD_HDR_WAIT set 2012/03/24 02:30:14.857| storeClientCopy2: returning because ENTRY_FWD_HDR_WAIT set 2012/03/24 02:30:14.857| InvokeHandlers: 04AFD5B6421D00FDA0A0720BDD377B00 2012/03/24 02:30:14.857| InvokeHandlers: 04AFD5B6421D00FDA0A0720BDD377B00 2012/03/24 02:30:14.857| StoreEntry::InvokeHandlers: checking client #0 2012/03/24 02:30:14.857| storeClientCopy2: 04AFD5B6421D00FDA0A0720BDD377B00 2012/03/24 02:30:14.857| store_client::doCopy: Copying normal from memory
section 92-93
section 92 Storage File System
section 93 Adaptation
section 93 ICAP (RFC 3507) Client
section 93 eCAP Interface
Протестировать данные фичи нет возможности (
Итоги (советы) для debug_options
Вот, собственно, это все возможные секции debug_options на данный момент для squid версии 3.1. Из всего приведенного выше, определенно могу сказать, что многие секции дублируют друг-друга, некоторые трудно диагностируемы, т.к. не использую данные технологии. Да и логи по каждой секции предоставить довольно проблематично по причине большего объема и ненаглядности… В связи с этим, я был бы очень благодарен читателям за предоставление образцов логов по секциям, по которым не удалось получить какую-либо информацию, либо за какие-то дополнения о применении не протестированных/не полноценно протестированных секций.
Для управления логированием и уменьшения уровня неактуальных сообщений в логах при масштабном внедрении squid можно использовать следующие директивы:
acl no_log src 192.168.2.0/26 log_access allow no_log log_access deny all
Думаю, что тут все довольно наглядно…. Мы хотим продиагностировать клиентов из подсети 192.168.2.0/26, при этом, нам не хотелось бы забивать лог информацией от других IP адресов. Мы задаем указанные правила и в лог попадают только указанные хосты. ИМХО, очень удобно.
Хочу так же привести наглядный пример использования debug_options из SQUID FAQ:
Я установил собственные контроли доступа, но они не работают! Почему?
Если ACL-лы – причина ваших проблем и вы не знаете почему они не работают, вы можете воспользоваться этой инструкцией, чтобы отладить их. В squid.conf включите отладку для секции 33 на уровне 2 (либо больше, если 2 уровня будет не достаточно). К примеру:
debug_options ALL,1 33,2
Потом перезапустите Squid. Теперь, ваш cache.log (и/или access.log ???) должен содержать строку для каждого запроса, которая поясняет запрещен или резрешен запрос и с каким ACL он совпал. Если это не дало вам достаточно информации, чтобы избавиться от проблемы, вы можете также включить детальную отладку процесса обработки ACL
debug_options ALL,1 33,2 28,9
Перезапустите Squid.
Теперь ваш cache.log (и/или access.log ???) должен содержать детальную трассировку всего процесса контроля доступа. Будьте внимательны, на каждый запрос будет по несколько несколько строк.
Ссылки
http://www.squid-cache.org/Doc/config/debug_options/
http://wiki.squid-cache.org/KnowledgeBase/DebugSections
http://www.squid-cache.org/Doc/config/
С Уважением, Mc.Sim!
Другие материалы в категории Linux
- Репликация Mysql (master-slave, master-master)
- Ошибка 0x80004005 0x80070035 на Windows 10 при доступе к сетевой папке
- Текстовый редактор VIM, основы работы
- Спринт Lingoda (ex Марафон Lingoda) + промокод.
- ddrescue или спасаем данные с HDD
- Бесплатный SLES для Vmware – ВСЁ…
- Резервное копирование файлов сайта по ssh
- SQUID настройка ACL и http_access
- squid, использование опции debug_options или диагностика компонентов squid
- Седьмой релиз Debian
Согласно этому вот это нам не поможет:
Для управления логированием и уменьшения уровня неактуальных сообщений в логах при масштабном внедрении squid можно использовать следующие директивы:Ты это точно применял? Я попробовал, а в cache.log все равно всё валится. Я не понял и почитал.
Нет, я это не применял.
Эта директива управляет логированием только той информацией, которая попадает в access.log (не cache.log).
Спасибо! Очень помогло