snik_1900 Posted June 26, 2017 Доброго дня. Может кто сталкивался с такой проблемой. Уже месяц бьюсь, решить не могу. Есть cisco по wccp2 подключенная к серверу на FreeBSD 11.0 с установленным SQUID. SQUID выполняет фильтрацию. CISCO в соответствии с Access-list заворачивает по IP нужные сайты на squid По HTTP фильтрует отлично. А по HTTPS не работает. Не пропускает все пришедшие запросы от cisco на HTTPS. #squid -v Squid Cache: Version 3.5.23 Service Name: squid configure options: '--with-default-user=squid' '--bindir=/usr/local/sbin' '--sbindir=/usr/local/sbin' '--datadir=/usr/local/etc/squid' '--libexecdir=/usr/local/libexec/squid' '--localstatedir=/var' '--sysconfdir=/usr/local/etc/squid' '--with-logdir=/var/log/squid' '--with-pidfile=/var/run/squid/squid.pid' '--with-swapdir=/var/squid/cache' '--without-gnutls' '--enable-auth' '--enable-zph-qos' '--enable-build-info' '--enable-loadable-modules' '--enable-removal-policies=lru heap' '--disable-epoll' '--disable-linux-netfilter' '--disable-linux-tproxy' '--disable-translation' '--disable-arch-native' '--enable-eui' '--enable-cache-digests' '--enable-delay-pools' '--disable-ecap' '--disable-esi' '--enable-follow-x-forwarded-for' '--enable-htcp' '--enable-icap-client' '--enable-icmp' '--enable-ident-lookups' '--enable-ipv6' '--enable-kqueue' '--with-large-files' '--enable-http-violations' '--without-nettle' '--enable-snmp' '--enable-ssl' '--with-openssl=/usr/local' 'LIBOPENSSL_CFLAGS=-I/usr/local/include' 'LIBOPENSSL_LIBS=-lcrypto -lssl' '--enable-ssl-crtd' '--disable-stacktraces' '--enable-forw-via-db' '--enable-wccp' '--enable-wccpv2' '--without-heimdal-krb5' '--without-mit-krb5' '--without-gss' '--disable-ipf-transparent' '--enable-ipfw-transparent' '--disable-pf-transparent' '--without-nat-devpf' '--enable-auth-basic=DB SMB_LM MSNT-multi-domain NCSA PAM POP3 RADIUS fake getpwnam NIS' '--enable-auth-digest=file' '--enable-external-acl-helpers=file_userip time_quota unix_group' '--enable-auth-negotiate=none' '--enable-auth-ntlm=fake smb_lm' '--enable-storeio=aufs diskd rock ufs' '--enable-disk-io=DiskThreads DiskDaemon AIO Blocking IpcIo Mmapped' '--enable-log-daemon-helpers=file' '--enable-url-rewrite-helpers=fake' '--enable-storeid-rewrite-helpers=file' '--prefix=/usr/local' '--mandir=/usr/local/man' '--disable-silent-rules' '--infodir=/usr/local/info/' '--build=amd64-portbld-freebsd11.0' 'build_alias=amd64-portbld-freebsd11.0' 'CC=cc' 'CFLAGS=-O2 -pipe -fstack-protector -fno-strict-aliasing' 'LDFLAGS= -pthread -Wl,-rpath,/usr/local/lib -fstack-protector' 'LIBS=' 'CPPFLAGS=' 'CXX=c++' 'CXXFLAGS=-O2 -pipe -fstack-protector -fno-strict-aliasing -Wno-unknown-warning-option -Wno-undefined-bool-conversion -Wno-tautological-undefined-compare -Wno-dynamic-class-memaccess' 'CPP=cpp' --enable-ltdl-convenience squid.conf: cache_effective_user squid cache_effective_group squid visible_hostname reestr-proxy #debug_options ALL,5 http_port 192.168.2.230:9090 http_port 192.168.2.230:3128 intercept https_port 192.168.2.230:3129 intercept ssl-bump generate-host-certificates=on dynamic_cert_mem_cache_size=4MB cert=/usr/local/etc/squid/squ always_direct allow all acl ssl_sites ssl::server_name "/var/db/zapret-info/denied_https.conf" acl step1 at_step SslBump1 acl step2 at_step SslBump2 ssl_bump peek step1 ssl_bump bump ssl_sites ssl_bump splice all sslproxy_cert_error allow all sslproxy_options NO_SSLv2,NO_SSLv3,SINGLE_ECDH_USE sslproxy_options ALL sslproxy_cipher ALL sslcrtd_program /usr/local/libexec/squid/ssl_crtd -s /var/squid/ssl_db -M 4MB icp_port 0 #hierarchy_stoplist cgi-bin ? acl QUERY urlpath_regex cgi-bin \? cache deny QUERY acl apache rep_header Server ^Apache cache_mem 1 MB cache_swap_low 90 cache_swap_high 95 maximum_object_size 1 KB maximum_object_size_in_memory 50 KB cache_replacement_policy heap LFUDA cache_dir ufs /var/squid/cache 1 1 1 no-store logfile_rotate 7 dns_nameservers 8.8.8.8 hosts_file /etc/hosts refresh_pattern ^ftp: 1440 20% 10080 refresh_pattern ^gopher: 1440 0% 1440 refresh_pattern . 0 20% 4320 quick_abort_min 0 KB quick_abort_max 0 KB half_closed_clients off acl purge method PURGE acl CONNECT method CONNECT acl SSL_ports port 16869 acl SSL_ports port 443 acl Safe_ports port 80 acl Safe_ports port 8001 acl Safe_ports port 81 acl Safe_ports port 888 http_access allow manager localhost http_access deny manager http_access allow purge localhost http_access deny purge http_access deny !Safe_ports http_access deny CONNECT !SSL_ports http_access allow localhost http_access allow all http_reply_access allow all icp_access allow all cache_mgr root@server.ru memory_pools off log_icp_queries off cachemgr_passwd q1w2e3r4 all client_db off buffered_logs on wccp2_router 192.168.2.229 wccp2_rebuild_wait on wccp2_forwarding_method 2 wccp2_return_method 2 wccp2_assignment_method 1 wccp2_service dynamic 0 wccp2_service_info 0 protocol=tcp flags=dst_ip_hash,dst_port_hash priority=240 ports=80,8001,8080,8081,81,888 wccp2_service dynamic 70 wccp2_service_info 70 protocol=tcp flags=dst_ip_hash,dst_port_hash priority=240 ports=16869,443 wccp2_address 192.168.2.230 redirect_program /usr/local/etc/squid/redirector.pl url_rewrite_children 60 startup=10 idle=1 concurrency=0 /var/log/squid/cache.log: 2017/06/22 23:54:18 kid1| Current Directory is /var/squid 2017/06/22 23:54:18 kid1| Starting Squid Cache version 3.5.23 for amd64-portbld-freebsd11.0... 2017/06/22 23:54:18 kid1| Service Name: squid 2017/06/22 23:54:18 kid1| Process ID 16050 2017/06/22 23:54:18 kid1| Process Roles: worker 2017/06/22 23:54:18 kid1| With 1171206 file descriptors available 2017/06/22 23:54:18 kid1| Initializing IP Cache... 2017/06/22 23:54:18 kid1| DNS Socket created at [::], FD 6 2017/06/22 23:54:18 kid1| DNS Socket created at 0.0.0.0, FD 7 2017/06/22 23:54:18 kid1| Adding nameserver 8.8.8.8 from squid.conf 2017/06/22 23:54:18 kid1| helperOpenServers: Starting 5/32 'ssl_crtd' processes 2017/06/22 23:54:18 kid1| helperOpenServers: Starting 10/60 'redirector.pl' processes 2017/06/22 23:54:18 kid1| Logfile: opening log daemon:/var/log/squid/access.log 2017/06/22 23:54:18 kid1| Logfile Daemon: opening log /var/log/squid/access.log 2017/06/22 23:54:18 kid1| Unlinkd pipe opened on FD 45 2017/06/22 23:54:18 kid1| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec 2017/06/22 23:54:18 kid1| Store logging disabled 2017/06/22 23:54:18 kid1| Swap maxSize 1024 + 1024 KB, estimated 157 objects 2017/06/22 23:54:18 kid1| Target number of buckets: 7 2017/06/22 23:54:18 kid1| Using 8192 Store buckets 2017/06/22 23:54:18 kid1| Max Mem size: 1024 KB 2017/06/22 23:54:18 kid1| Max Swap size: 1024 KB 2017/06/22 23:54:18 kid1| Rebuilding storage in /var/squid/cache (clean log) 2017/06/22 23:54:18 kid1| Using Least Load store dir selection 2017/06/22 23:54:18 kid1| Current Directory is /var/squid 2017/06/22 23:54:18 kid1| Finished loading MIME types and icons. 2017/06/22 23:54:18 kid1| Accepting WCCPv2 messages on port 2048, FD 48. 2017/06/22 23:54:18 kid1| Initialising all WCCPv2 lists 2017/06/22 23:54:18 kid1| HTCP Disabled. 2017/06/22 23:54:18 kid1| Pinger socket opened on FD 53 2017/06/22 23:54:18 kid1| Squid plugin modules loaded: 0 2017/06/22 23:54:18 kid1| Adaptation support is off. 2017/06/22 23:54:18 kid1| Accepting HTTP Socket connections at local=192.168.2.230:9090 remote=[::] FD 49 flags=9 2017/06/22 23:54:18 kid1| Accepting NAT intercepted HTTP Socket connections at local=192.168.2.230:3128 remote=[::] FD 50 flags=41 2017/06/22 23:54:18 kid1| Accepting NAT intercepted SSL bumped HTTPS Socket connections at local=192.168.2.230:3129 remote=[::] FD 51 flags= 2017/06/22 23:54:18 kid1| Done reading /var/squid/cache swaplog (0 entries) 2017/06/22 23:54:18 kid1| Store rebuilding is 0.00% complete 2017/06/22 23:54:18 kid1| Finished rebuilding storage from disk. 2017/06/22 23:54:18 kid1| 0 Entries scanned 2017/06/22 23:54:18 kid1| 0 Invalid entries. 2017/06/22 23:54:18 kid1| 0 With invalid flags. 2017/06/22 23:54:18 kid1| 0 Objects loaded. 2017/06/22 23:54:18 kid1| 0 Objects expired. 2017/06/22 23:54:18 kid1| 0 Objects cancelled. 2017/06/22 23:54:18 kid1| 0 Duplicate URLs purged. 2017/06/22 23:54:18 kid1| 0 Swapfile clashes avoided. 2017/06/22 23:54:18 kid1| Took 0.03 seconds ( 0.00 objects/sec). 2017/06/22 23:54:18 kid1| Beginning Validation Procedure 2017/06/22 23:54:18 kid1| Completed Validation Procedure 2017/06/22 23:54:18 kid1| Validated 0 Entries 2017/06/22 23:54:18 kid1| store_swap_size = 0.00 KB 2017/06/22 23:54:18| pinger: Initialising ICMP pinger ... 2017/06/22 23:54:18| pinger: ICMP socket opened. 2017/06/22 23:54:18| pinger: ICMPv6 socket opened 2017/06/22 23:54:19 kid1| storeLateRelease: released 0 objects При этом /var/squid/ssl_db: index.txt 0 size 1 каталог certs - пустой #sockstat -4 | grep 3129 squid squid 16050 51 tcp4 192.168.2.230:3129 *:* #sockstat -4 | grep 3128 squid squid 16050 50 tcp4 192.168.2.230:3128 *:* # ipfw list 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 80 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 8001 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 8080 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 8081 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 81 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 888 via igb1 in 00050 fwd 192.168.2.230,3129 tcp from not me to any dst-port 16869 via igb1 in 00050 fwd 192.168.2.230,3129 tcp from not me to any dst-port 443 via igb1 in Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
alibek Posted June 27, 2017 Запросы на сквид вообще не приходят? Или приходят, но не обслуживаются? Коневой самоподписанный CA установлен у клиентов? А вообще я бы советовал не тратить время, через сквид блокировку сайтов не обеспечить. Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted June 27, 2017 Запросы на сквид вообще не приходят? В логах ничего не отображается. Или приходят, но не обслуживаются? Скорее всего. Коневой самоподписанный CA установлен у клиентов? SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. А вообще я бы советовал не тратить время, через сквид блокировку сайтов не обеспечить. Уже 2 года работает. Проблема только с https. Раньше не обращали внимания, а после проблем с DNSами озадачились. Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
alibek Posted June 27, 2017 В логах ничего не отображается. Так надо tcpdump смотреть. SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. Какая-то загадочная фраза. Насколько я знаю, через сквид пропускать https-трафик только с помощью MITM, установив у клиентов свой корневой CA и подписывая им поддельные сертификаты. Может конечно путаю с чем-то, но каким образом сквид извлечет из зашифрованного трафика строку запроса? Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted June 27, 2017 snik_1900 (Сегодня, 09:50) писал: В логах ничего не отображается. Так надо tcpdump смотреть. Если погасить squid, то https-ные сайты начинают открываться не блокируясь. Значит на сервак запросы попадают. snik_1900 (Сегодня, 09:50) писал: SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. Какая-то загадочная фраза. Насколько я знаю, через сквид пропускать https-трафик только с помощью MITM, установив у клиентов свой корневой CA и подписывая им поддельные сертификаты. Может конечно путаю с чем-то, но каким образом сквид извлечет из зашифрованного трафика строку запроса? За основу взята идя: http://www.ps-ax.ru/2017/04/12/%D1%84%D0%B8%D0%BB%D1%8C%D1%82%D1%80%D0%B0%D1%86%D0%B8%D1%8F-%D0%BF%D0%BE-%D1%80%D0%B5%D0%B5%D1%81%D1%82%D1%80%D1%83-%D1%80%D0%BE%D1%81%D0%BA%D0%BE%D0%BC%D0%BD%D0%B0%D0%B4%D0%B7%D0%BE%D1%80%D0%B0/ Как я понимаю он смотрит в step1 SslBump1 имя домена. Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
alibek Posted June 27, 2017 Любопытно, пожалуй действительно должно работать (на уровне доменов, конечно, а не URL). Но на https нельзя сделать редирект или показать заглушку, можно только разорвать соединение. Скорее всего в этом этапе что-то не срабатывает. Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
alibek Posted June 27, 2017 Кстати, в конфиге я не вижу ssl_bump terminate ssl_sites Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted June 27, 2017 (edited) Кстати, в конфиге я не вижу ssl_bump terminate ssl_sites А зачем? Есть: ssl_bump bump ssl_sites и ssl_bump peek step1. Edited June 27, 2017 by snik_1900 Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted July 6, 2017 Свежих мыслей нет? Или SQUID редкий зверь? Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
Ivan_83 Posted July 6, 2017 SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. Сертификат у клиента должен стоять в любом случае, иначе он будет показывать ошибку, потому что не доверенное. Что тебе тцпдам показывает? Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted July 6, 2017 snik_1900 (27 июня 2017 - 09:50) писал: SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. Сертификат у клиента должен стоять в любом случае, иначе он будет показывать ошибку, потому что не доверенное. Да и флаг переполнения ему в регистр. Если ssl_bump сработает то клиент ничего не получит вообще, а если нет то запрос дальше полетит без изменений. Что тебе тцпдам показывает? Ну например вот такое: #tcpdump -i igb1 16:52:31.245083 IP AAA.BBB.CCC.DDD.4299 > 13.32.121.171.https: Flags , seq 2500963771, win 65535, options [mss 1440,nop,nop,sackOK], length 0 или такое: #tcpdump -i igb1 16:52:31.262933 IP AAA.BBB.CCC.DDD.58348 > ec2-52-58-31-242.eu-central-1.compute.amazonaws.com.https: Flags , seq 1501894797, win 14600, options [mss 1440,sackOK,TS val 252272 ecr 0,nop,wscale 6], length 0 Как я понимаю до сервака пакеты добегают. А правило ipfw: 00050 fwd 192.168.2.230,3129 tcp from not me to any dst-port 443 via igb1 in перегоняет с 443 порта на 3129. Или я чего-то недопонимаю? Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
Ivan_83 Posted July 6, 2017 Я вот не уверен что fwd делает dst nat. У меня на PF rdr вроде делает Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted July 7, 2017 Я вот не уверен что fwd делает dst nat. У меня на PF rdr вроде делает Но правила: 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 80 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 8001 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 8080 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 8081 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 81 via igb1 in 00050 fwd 192.168.2.230,3128 tcp from not me to any dst-port 888 via igb1 in работают. Думаю попробовать изменить в настройках squid wccp2_service dynamic 0 wccp2_service_info 0 protocol=tcp flags=dst_ip_hash,dst_port_hash priority=240 ports=80,8001,8080,8081,81,888 wccp2_service dynamic 70 wccp2_service_info 70 protocol=tcp flags=dst_ip_hash,dst_port_hash priority=240 ports=16869,443 на wccp2_service dynamic 80 wccp2_service_info 80 protocol=tcp flags=dst_ip_hash,dst_port_hash priority=240 ports=80,8001,8080,8081,81,888 wccp2_service dynamic 70 wccp2_service_info 70 protocol=tcp flags=dst_ip_hash,dst_port_hash priority=240 ports=16869,443 Может он тупо не понимает dynamic с № меньше 50 и весть трафик гонит на 0й? Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted July 18, 2017 (edited) Удалось добиться: При попытке открыть https://www.avito.ru сначала попадаю на страничку с предупреждение о возможной подмене сертификата, а потом страничка access denied от squida. Стали генерироваться squid'ом временные сертификаты. Сайт https://www.avito.ru не должен блокироваться (в файле /var/db/zapret-info/denied_https.conf (см. конфиг в первом посте) его нет). То же самое происходит и с https-сайтами имеющимися в /var/db/zapret-info/denied_https.conf. 1) cache.log 2017/07/17 21:17:38 kid1| Error negotiating SSL connection on FD 6660: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown (1/0) 2017/07/17 21:17:39 kid1| Error negotiating SSL connection on FD 6660: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown (1/0) 2017/07/17 21:17:39 kid1| Error negotiating SSL connection on FD 6660: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown (1/0) 2017/07/17 21:17:39 kid1| Error negotiating SSL connection on FD 7909: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown (1/0) 2017/07/17 21:17:44 kid1| Error negotiating SSL connection on FD 1280: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown (1/0) 2) access.log Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TCP_DENIED/200 0 CONNECT 185.89.12.132:443 - HIER_NONE/- - Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TAG_NONE/403 3851 GET https://www.avito.ru/ - HIER_NONE/- text/html Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TCP_DENIED/200 0 CONNECT 185.89.12.132:443 - HIER_NONE/- - Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TCP_DENIED/200 0 CONNECT 185.89.12.132:443 - HIER_NONE/- - Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TAG_NONE/403 3851 GET http://reestr-proxy:9090/squid-internal-static/icons/SN.png - HIER_NONE/- text/html Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TCP_DENIED/200 0 CONNECT 185.89.12.132:443 - HIER_NONE/- - Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TCP_DENIED/200 0 CONNECT 185.89.12.132:443 - HIER_NONE/- - Mon Jul 17 21:17:09 2017 0 AAA.BBB.CCC.DDD TAG_NONE/403 3851 GET https://www.avito.ru/favicon.ico - HIER_NONE/- text/html 3) данные в файле denied_https.conf хранятся в формате без "https://": azartpay1.com azartpay1.top azartpay1.xyz azartplay-casino-game.club azartplay-casino-game1.space azartplay-casino-games.top azartplay-casino-online.com azartplay-casino.club azartplay-casinogamez.top azartplay-club.com azartplay-online.com azartplay-online.foot-bol.com azartplay.casino-rate.com azartplay.cc azartplay.com azartplay.foot-bol.com azartplay.igryflash.com Edited July 18, 2017 by snik_1900 Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted August 10, 2017 (edited) Может это поможет найти проблему. Более детальный лог: 2017/08/11 00:24:35.492 kid1| 83,2| client_side.cc(3828) clientNegotiateSSL: clientNegotiateSSL: New session 0x8320c4a00 on FD 77 (EEE.FFF.GGG.HHHH:52244) 2017/08/11 00:24:35.492 kid1| 83,3| client_side.cc(3832) clientNegotiateSSL: clientNegotiateSSL: FD 77 negotiated cipher AES128-GCM-SHA256 2017/08/11 00:24:35.492 kid1| 83,5| client_side.cc(3848) clientNegotiateSSL: clientNegotiateSSL: FD 77 has no certificate. 2017/08/11 00:24:35.492 kid1| 33,4| client_side.cc(231) readSomeData: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52244 FD 77 flags=33: reading request... 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f718=6 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f718 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f718=7 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f718 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f718=8 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f718=9 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f718=8 2017/08/11 00:24:35.492 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::clientReadRequest constructed, this=0x8322486e0 [call1683] 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f718 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f718=9 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f718=10 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f718=9 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f718=8 2017/08/11 00:24:35.492 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f718=7 2017/08/11 00:24:35.493 kid1| 5,5| Read.cc(58) comm_read_base: comm_read, queueing read for local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52244 FD 77 flags=33; asynCall 0x8322486e0*1 2017/08/11 00:24:35.493 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 77, type=1, handler=1, client_data=0x8246028f0, timeout=0 2017/08/11 00:24:35.493 kid1| 83,5| bio.cc(118) read: FD 78 read 11 <= 11 2017/08/11 00:24:35.493 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes 2017/08/11 00:24:35.493 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(247) read: SSL Header: 1603010200010001fc0303102c318c03ce1ede451c1b09d9f3f11830ecb6268b4faa7230b571d915a4ee3220a944e53879f9f759c4f6bd749bdee85bc6f251a834b4db985fa11345d6952b53001ccca9cca8cc14cc13c02bc02fc00ac014c009c013009c0035002f000a01000197ff0100010000000011000f00000c7777772e617669746f2e727500170000002300c0fac6c40c4f055a5d06c17cbda137846514bc861d812d34e376b4e921a43ccf51589633baa2bcf6fb90c06b413f4ec7cca1aa1ff6c32e9f480b591ff6a87297605812c07105144cec80c84653e7c7a129fde45c10f1572cbc16aa68cb919b3bbd0c8008c5731ab6bcf4284ec48b92ae92a225e36f9d656b3a70166f242349d027c560d2256cf39173c779b36eeb2807860c34266ebb207542974e32ffbfe094e23d5876a452b800c6635dc602736ed72c892a962014e693bb96579866b26376fc000d001600140601060305010503040104030301030302010203000500050100000000337400000012000000100017001502683208737064792f332e3108687474702f312e3175500000000b00020100000a000600040017001800150057000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(761) parseMsgHead: SSL Header: 1603010200010001fc0303102c318c03ce1ede451c1b09d9f3f11830ecb6268b4faa7230b571d915a4ee3220a944e53879f9f759c4f6bd749bdee85bc6f251a834b4db985fa11345d6952b53001ccca9cca8cc14cc13c02bc02fc00ac014c009c013009c0035002f000a01000197ff0100010000000011000f00000c7777772e617669746f2e727500170000002300c0fac6c40c4f055a5d06c17cbda137846514bc861d812d34e376b4e921a43ccf51589633baa2bcf6fb90c06b413f4ec7cca1aa1ff6c32e9f480b591ff6a87297605812c07105144cec80c84653e7c7a129fde45c10f1572cbc16aa68cb919b3bbd0c8008c5731ab6bcf4284ec48b92ae92a225e36f9d656b3a70166f242349d027c560d2256cf39173c779b36eeb2807860c34266ebb207542974e32ffbfe094e23d5876a452b800c6635dc602736ed72c892a962014e693bb96579866b26376fc000d001600140601060305010503040104030301030302010203000500050100000000337400000012000000100017001502683208737064792f332e3108687474702f312e3175500000000b00020100000a000600040017001800150057000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2071 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 517 for SBuf2071 2017/08/11 00:24:35.493 kid1| 24,8| SBuf.cc(956) cow: SBuf2071 new size:517 2017/08/11 00:24:35.493 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2071 new size: 517 2017/08/11 00:24:35.493 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130510 id=blob656 reserveSize=517 2017/08/11 00:24:35.493 kid1| 24,8| MemBlob.cc(102) memAlloc: blob656 memAlloc: requested=517, received=1024 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2071 new store capacity: 1024 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(995) parseV3Hello: Get fake features from v3 ClientHello message. 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(998) parseV3Hello: ClientHello message size: 512 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1021) parseV3Hello: Client random: 102c318c03ce1ede451c1b09d9f3f11830ecb6268b4faa7230b571d915a4ee32 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1025) parseV3Hello: Session ID Length: 32 2017/08/11 00:24:35.493 kid1| 24,6| SBuf.cc(153) assign: SBuf2070 from c-string, n=32) 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2070 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 32 for SBuf2070 2017/08/11 00:24:35.493 kid1| 24,8| SBuf.cc(956) cow: SBuf2070 new size:32 2017/08/11 00:24:35.493 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2070 new size: 32 2017/08/11 00:24:35.493 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130990 id=blob657 reserveSize=32 2017/08/11 00:24:35.493 kid1| 24,8| MemBlob.cc(102) memAlloc: blob657 memAlloc: requested=32, received=40 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2070 new store capacity: 40 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1067) parseV3Hello: Ciphers requested by client: ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:AES128-GCM-SHA256:AES256-SHA:AES128-SHA:DES-CBC3-SHA 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1076) parseV3Hello: SSL compression methods number: 1 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: ff01 of size:1 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 0 of size:11 2017/08/11 00:24:35.493 kid1| 24,6| SBuf.cc(153) assign: SBuf2068 from c-string, n=12) 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2068 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 12 for SBuf2068 2017/08/11 00:24:35.493 kid1| 24,8| SBuf.cc(956) cow: SBuf2068 new size:12 2017/08/11 00:24:35.493 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2068 new size: 12 2017/08/11 00:24:35.493 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130960 id=blob658 reserveSize=12 2017/08/11 00:24:35.493 kid1| 24,8| MemBlob.cc(102) memAlloc: blob658 memAlloc: requested=12, received=40 2017/08/11 00:24:35.493 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2068 new store capacity: 40 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1110) parseV3Hello: Found server name: www.avito.ru 2017/08/11 00:24:35.493 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 17 of size:0 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 23 of size:c0 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: d of size:16 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 5 of size:5 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 3374 of size:0 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 12 of size:0 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 10 of size:17 2017/08/11 00:24:35.494 kid1| 24,6| SBuf.cc(153) assign: SBuf2069 from c-string, n=21) 2017/08/11 00:24:35.494 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2069 2017/08/11 00:24:35.494 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 21 for SBuf2069 2017/08/11 00:24:35.494 kid1| 24,8| SBuf.cc(956) cow: SBuf2069 new size:21 2017/08/11 00:24:35.494 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2069 new size: 21 2017/08/11 00:24:35.494 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130900 id=blob659 reserveSize=21 2017/08/11 00:24:35.494 kid1| 24,8| MemBlob.cc(102) memAlloc: blob659 memAlloc: requested=21, received=40 2017/08/11 00:24:35.494 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2069 new store capacity: 40 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 7550 of size:0 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: b of size:2 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: a of size:6 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(1094) parseV3Hello: TLS Extension: 15 of size:57 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(574) squid_bio_ctrl: 0x80318fd40 6(0, 0x80318f720) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3RCH_A (SSLv3 read client hello A) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3WSH_A (SSLv3 write server hello A) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3WSC_A (SSLv3 write certificate A) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3WSD_A (SSLv3 write server done A) 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(95) write: FD 78 wrote 826 <= 826 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(574) squid_bio_ctrl: 0x80318fd40 11(0, 0x0) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3FLUSH (SSLv3 flush data) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3RCC_A (SSLv3 read client certificate A) 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(118) read: FD 78 read -1 <= 5 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(123) read: error: 35 ignored: 1 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2002 3RCKEA (SSLv3 read client key exchange A) 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2002 3RCKEA (SSLv3 read client key exchange A) 2017/08/11 00:24:35.494 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 78, type=1, handler=1, client_data=0x83210f998, timeout=0 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(118) read: FD 79 read 11 <= 11 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(247) read: SSL Header: 1603010200010001fc0303fbb9c140a0fceed6a16bab1bd2df76f3c2306c3b8170cd07bd3fb7aa1d18668b20a944e53879f9f759c4f6bd749bdee85bc6f251a834b4db985fa11345d6952b53001ccca9cca8cc14cc13c02bc02fc00ac014c009c013009c0035002f000a01000197ff0100010000000011000f00000c7777772e617669746f2e727500170000002300c0fac6c40c4f055a5d06c17cbda137846514bc861d812d34e376b4e921a43ccf51589633baa2bcf6fb90c06b413f4ec7cca1aa1ff6c32e9f480b591ff6a87297605812c07105144cec80c84653e7c7a129fde45c10f1572cbc16aa68cb919b3bbd0c8008c5731ab6bcf4284ec48b92ae92a225e36f9d656b3a70166f242349d027c560d2256cf39173c779b36eeb2807860c34266ebb207542974e32ffbfe094e23d5876a452b800c6635dc602736ed72c892a962014e693bb96579866b26376fc000d001600140601060305010503040104030301030302010203000500050100000000337400000012000000100017001502683208737064792f332e3108687474702f312e3175500000000b00020100000a00060004001700180015005700000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 2017/08/11 00:24:35.494 kid1| 83,7| bio.cc(168) stateChanged: FD 79 now: 0x2002 23RCHA (SSLv2/v3 read client hello A) 2017/08/11 00:24:35.494 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 79, type=1, handler=1, client_data=0x83210fc18, timeout=0 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(118) read: FD 80 read 11 <= 11 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes 2017/08/11 00:24:35.494 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello 2017/08/11 00:24:35.495 kid1| 83,7| bio.cc(247) read: SSL Header: 1603010200010001fc0303366070b673672d2875627f31f4dac5db9a67575e26e5d15a9a57384ced70e12a20a944e53879f9f759c4f6bd749bdee85bc6f251a834b4db985fa11345d6952b53001ccca9cca8cc14cc13c02bc02fc00ac014c009c013009c0035002f000a01000197ff0100010000000011000f00000c7777772e617669746f2e727500170000002300c0fac6c40c4f055a5d06c17cbda137846514bc861d812d34e376b4e921a43ccf51589633baa2bcf6fb90c06b413f4ec7cca1aa1ff6c32e9f480b591ff6a87297605812c07105144cec80c84653e7c7a129fde45c10f1572cbc16aa68cb919b3bbd0c8008c5731ab6bcf4284ec48b92ae92a225e36f9d656b3a70166f242349d027c560d2256cf39173c779b36eeb2807860c34266ebb207542974e32ffbfe094e23d5876a452b800c6635dc602736ed72c892a962014e693bb96579866b26376fc000d001600140601060305010503040104030301030302010203000500050100000000337400000012000000100017001502683208737064792f332e3108687474702f312e3175500000000b00020100000a0006000400170018001500570000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 2017/08/11 00:24:35.495 kid1| 83,7| bio.cc(168) stateChanged: FD 80 now: 0x2002 23RCHA (SSLv2/v3 read client hello A) 2017/08/11 00:24:35.495 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 80, type=1, handler=1, client_data=0x83210fe98, timeout=0 2017/08/11 00:24:35.495 kid1| 5,5| Write.cc(66) HandleWrite: local=AAA.BBB.CCC.DDD:55024 remote=185.5.53.26:80 FD 75 flags=1: off 0, sz 478. 2017/08/11 00:24:35.495 kid1| 5,5| Write.cc(108) HandleWrite: write() returns 478 2017/08/11 00:24:35.495 kid1| 5,3| IoCallback.cc(116) finish: called for local=AAA.BBB.CCC.DDD:55024 remote=185.5.53.26:80 FD 75 flags=1 (0, 0) 2017/08/11 00:24:35.495 kid1| 11,5| AsyncCall.cc(93) ScheduleCall: IoCallback.cc(135) will call HttpStateData::sentRequestBody(local=AAA.BBB.CCC.DDD:55024 remote=185.5.53.26:80 FD 75 flags=1, data=0x8321f4a18) [call1681] 2017/08/11 00:24:35.495 kid1| 5,5| AsyncCallQueue.cc(55) fireNext: entering httpsAccept(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33, MXID_55) 2017/08/11 00:24:35.495 kid1| 5,5| AsyncCall.cc(38) make: make call httpsAccept [call1682] 2017/08/11 00:24:35.495 kid1| 33,4| client_side.cc(3952) httpsAccept: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 accepted, starting SSL negotiation. 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x832110118 2017/08/11 00:24:35.495 kid1| 93,5| AsyncJob.cc(34) AsyncJob: AsyncJob constructed, this=0x8321102e0 type=Http::Server [job209] 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2128 created 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2129 created 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2130 created 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2131 created 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=1 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=2 2017/08/11 00:24:35.495 kid1| 93,5| AsyncCall.cc(26) AsyncCall: The AsyncCall AsyncJob::start constructed, this=0x80318edf0 [call1684] 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=3 2017/08/11 00:24:35.495 kid1| 93,5| AsyncCall.cc(93) ScheduleCall: AsyncJob.cc(26) will call AsyncJob::start() [call1684] 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=2 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=1 2017/08/11 00:24:35.495 kid1| 5,5| AsyncCallQueue.cc(57) fireNext: leaving httpsAccept(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33, MXID_55) 2017/08/11 00:24:35.495 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::clientReadRequest(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 FD 74 flags=33, data=0x83210f218) 2017/08/11 00:24:35.495 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::clientReadRequest [call1669] 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.495 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job191] 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.495 kid1| 33,5| client_side.cc(3283) clientReadRequest: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 FD 74 flags=33 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(169) reserve: SBuf1960 was: 0+0+64=128 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(956) cow: SBuf1960 new size:4096 2017/08/11 00:24:35.495 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf1960 new size: 4096 2017/08/11 00:24:35.495 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x8321309c0 id=blob660 reserveSize=4096 2017/08/11 00:24:35.495 kid1| 24,8| MemBlob.cc(102) memAlloc: blob660 memAlloc: requested=4096, received=4096 2017/08/11 00:24:35.495 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320c8de0 id=blob616 capacity=128 size=64 2017/08/11 00:24:35.495 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf1960 new store capacity: 4096 2017/08/11 00:24:35.495 kid1| 24,7| SBuf.cc(185) reserve: SBuf1960 now: 0+0+4096=4096 2017/08/11 00:24:35.495 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f218=8 2017/08/11 00:24:35.495 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 4096 for SBuf1960 2017/08/11 00:24:35.495 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf1960 not growing 2017/08/11 00:24:35.495 kid1| 83,5| bio.cc(118) read: FD 74 read 0 <= 5 2017/08/11 00:24:35.496 kid1| 5,3| Read.cc(91) ReadNow: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 FD 74 flags=33, size 4096, retval 0, errno 0 2017/08/11 00:24:35.496 kid1| 33,5| client_side.cc(3323) clientReadRequest: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 FD 74 flags=33 closed? 2017/08/11 00:24:35.496 kid1| 33,4| client_side.cc(2421) connFinishedWithConn: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 FD 74 flags=33 closed 2017/08/11 00:24:35.496 kid1| 5,3| comm.cc(868) _comm_close: comm_close: start closing FD 74 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall commStartSslClose constructed, this=0x80318f9c0 [call1685] 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(93) ScheduleCall: comm.cc(902) will call commStartSslClose(FD 74) [call1685] 2017/08/11 00:24:35.496 kid1| 5,3| comm.cc(540) commUnsetFdTimeout: Remove timeout for FD 74 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=7 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=6 2017/08/11 00:24:35.496 kid1| 5,5| comm.cc(721) commCallCloseHandlers: commCallCloseHandlers: FD 74 2017/08/11 00:24:35.496 kid1| 5,5| comm.cc(729) commCallCloseHandlers: commCallCloseHandlers: ch->handler=0x8320a7d00*1 2017/08/11 00:24:35.496 kid1| 33,5| AsyncCall.cc(93) ScheduleCall: comm.cc(730) will call ConnStateData::connStateClosed(FD -1, data=0x83210f218) [call1601] 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall comm_close_complete constructed, this=0x80318fa30 [call1686] 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(93) ScheduleCall: comm.cc(941) will call comm_close_complete(FD 74) [call1686] 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=5 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.496 kid1| 33,5| AsyncJob.cc(152) callEnd: Http::Server status out: [ job191] 2017/08/11 00:24:35.496 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::clientReadRequest(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 flags=33, data=0x83210f218) 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=4 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=3 2017/08/11 00:24:35.496 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::clientReadRequest(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 FD 76 flags=33, data=0x83210f498) 2017/08/11 00:24:35.496 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::clientReadRequest [call1671] 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.496 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job194] 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.496 kid1| 33,5| client_side.cc(3283) clientReadRequest: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 FD 76 flags=33 2017/08/11 00:24:35.496 kid1| 24,8| SBuf.cc(169) reserve: SBuf1997 was: 0+0+64=128 2017/08/11 00:24:35.496 kid1| 24,8| SBuf.cc(956) cow: SBuf1997 new size:4096 2017/08/11 00:24:35.496 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf1997 new size: 4096 2017/08/11 00:24:35.496 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x8320c8de0 id=blob661 reserveSize=4096 2017/08/11 00:24:35.496 kid1| 24,8| MemBlob.cc(102) memAlloc: blob661 memAlloc: requested=4096, received=4096 2017/08/11 00:24:35.496 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320922c0 id=blob621 capacity=128 size=64 2017/08/11 00:24:35.496 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf1997 new store capacity: 4096 2017/08/11 00:24:35.496 kid1| 24,7| SBuf.cc(185) reserve: SBuf1997 now: 0+0+4096=4096 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x83210f498=8 2017/08/11 00:24:35.496 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 4096 for SBuf1997 2017/08/11 00:24:35.496 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf1997 not growing 2017/08/11 00:24:35.496 kid1| 83,5| bio.cc(118) read: FD 76 read 0 <= 5 2017/08/11 00:24:35.496 kid1| 5,3| Read.cc(91) ReadNow: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 FD 76 flags=33, size 4096, retval 0, errno 0 2017/08/11 00:24:35.496 kid1| 33,5| client_side.cc(3323) clientReadRequest: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 FD 76 flags=33 closed? 2017/08/11 00:24:35.496 kid1| 33,4| client_side.cc(2421) connFinishedWithConn: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 FD 76 flags=33 closed 2017/08/11 00:24:35.496 kid1| 5,3| comm.cc(868) _comm_close: comm_close: start closing FD 76 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall commStartSslClose constructed, this=0x803190280 [call1687] 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(93) ScheduleCall: comm.cc(902) will call commStartSslClose(FD 76) [call1687] 2017/08/11 00:24:35.496 kid1| 5,3| comm.cc(540) commUnsetFdTimeout: Remove timeout for FD 76 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=7 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=6 2017/08/11 00:24:35.496 kid1| 5,5| comm.cc(721) commCallCloseHandlers: commCallCloseHandlers: FD 76 2017/08/11 00:24:35.496 kid1| 5,5| comm.cc(729) commCallCloseHandlers: commCallCloseHandlers: ch->handler=0x8320a8fc0*1 2017/08/11 00:24:35.496 kid1| 33,5| AsyncCall.cc(93) ScheduleCall: comm.cc(730) will call ConnStateData::connStateClosed(FD -1, data=0x83210f498) [call1613] 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall comm_close_complete constructed, this=0x8031902f0 [call1688] 2017/08/11 00:24:35.496 kid1| 5,4| AsyncCall.cc(93) ScheduleCall: comm.cc(941) will call comm_close_complete(FD 76) [call1688] 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=5 2017/08/11 00:24:35.496 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.497 kid1| 33,5| AsyncJob.cc(152) callEnd: Http::Server status out: [ job194] 2017/08/11 00:24:35.497 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::clientReadRequest(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 flags=33, data=0x83210f498) 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=4 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=3 2017/08/11 00:24:35.497 kid1| 11,5| AsyncCallQueue.cc(55) fireNext: entering HttpStateData::sentRequestBody(local=AAA.BBB.CCC.DDD:55024 remote=185.5.53.26:80 FD 75 flags=1, data=0x8321f4a18) 2017/08/11 00:24:35.497 kid1| 11,5| AsyncCall.cc(38) make: make call HttpStateData::sentRequestBody [call1681] 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 11,5| AsyncJob.cc(123) callStart: HttpStateData status in: [ job208] 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 11,5| Client.cc(360) sentRequestBody: sentRequestBody: FD 75: size 478: errflag 0. 2017/08/11 00:24:35.497 kid1| 32,3| Client.cc(361) sentRequestBody: sentRequestBody called 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 91,7| BodyPipe.cc(381) postConsume: consumed 143 bytes [143<=143<=143 0+2047 pipe0x8320a9258 cons0x8321f4a28] 2017/08/11 00:24:35.497 kid1| 9,3| Client.cc(417) sendMoreRequestBody: will write 143 request body bytes 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8321f4a18=10 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8321f4a18=11 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8321f4a18=12 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8321f4a18=13 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8321f4a18=12 2017/08/11 00:24:35.497 kid1| 93,3| AsyncCall.cc(26) AsyncCall: The AsyncCall Client::sentRequestBody constructed, this=0x832248500 [call1689] 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8321f4a18=13 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8321f4a18=14 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8321f4a18=13 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8321f4a18=12 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8321f4a18=11 2017/08/11 00:24:35.497 kid1| 5,5| Write.cc(35) Write: local=AAA.BBB.CCC.DDD:55024 remote=185.5.53.26:80 FD 75 flags=1: sz 143: asynCall 0x832248500*1 2017/08/11 00:24:35.497 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 75, type=2, handler=1, client_data=0x824602820, timeout=0 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8321f4a18 2017/08/11 00:24:35.497 kid1| 11,5| AsyncJob.cc(152) callEnd: HttpStateData status out: [ job208] 2017/08/11 00:24:35.497 kid1| 11,5| AsyncCallQueue.cc(57) fireNext: leaving HttpStateData::sentRequestBody(local=AAA.BBB.CCC.DDD:55024 remote=185.5.53.26:80 FD 75 flags=1, data=0x8321f4a18) 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8321f4a18=10 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8321f4a18=9 2017/08/11 00:24:35.497 kid1| 93,5| AsyncCallQueue.cc(55) fireNext: entering AsyncJob::start() 2017/08/11 00:24:35.497 kid1| 93,5| AsyncCall.cc(38) make: make call AsyncJob::start [call1684] 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 93,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job209] 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=2 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=3 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=4 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=5 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=4 2017/08/11 00:24:35.497 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::connStateClosed constructed, this=0x8322485a0 [call1690] 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=5 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=6 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=5 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=4 2017/08/11 00:24:35.497 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=3 2017/08/11 00:24:35.498 kid1| 5,5| comm.cc(994) comm_add_close_handler: comm_add_close_handler: FD 82, AsyncCall=0x8322485a0*1 2017/08/11 00:24:35.498 kid1| 33,5| client_side.cc(3970) postHttpsAccept: accept transparent connection: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 2017/08/11 00:24:35.498 kid1| 55,7| HttpHeader.cc(446) HttpHeader: init-ing hdr: 0x802d98d18 owner: 2 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2132 created 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2133 created 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2134 created 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2133 from SBuf2134 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2134 destructed 2017/08/11 00:24:35.498 kid1| 23,3| ../src/HttpRequest.h(82) SetHost: HttpRequest::SetHost() given IP: 185.89.12.132 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x802e16f18 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802b760f8=1 2017/08/11 00:24:35.498 kid1| 28,3| Checklist.cc(70) preCheck: 0x802e16f18 checking slow rules 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=4 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x802b760f8 2017/08/11 00:24:35.498 kid1| 28,5| Acl.cc(138) matches: checking (ssl_bump rules) 2017/08/11 00:24:35.498 kid1| 28,5| Checklist.cc(400) bannedAction: Action 'ALLOWED/3' is not banned 2017/08/11 00:24:35.498 kid1| 28,5| Acl.cc(138) matches: checking (ssl_bump rule) 2017/08/11 00:24:35.498 kid1| 28,5| Acl.cc(138) matches: checking step1 2017/08/11 00:24:35.498 kid1| 28,3| Acl.cc(158) matches: checked: step1 = 1 2017/08/11 00:24:35.498 kid1| 28,3| Acl.cc(158) matches: checked: (ssl_bump rule) = 1 2017/08/11 00:24:35.498 kid1| 28,3| Acl.cc(158) matches: checked: (ssl_bump rules) = 1 2017/08/11 00:24:35.498 kid1| 28,3| Checklist.cc(63) markFinished: 0x802e16f18 answer ALLOWED for match 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802b760f8=0 2017/08/11 00:24:35.498 kid1| 28,3| Checklist.cc(163) checkCallback: ACLChecklist::checkCallback: 0x802e16f18 answer=ALLOWED 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=3 2017/08/11 00:24:35.498 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.498 kid1| 33,2| client_side.cc(3928) httpsSslBumpAccessCheckDone: sslBump needed for local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 method 3 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2135 created 2017/08/11 00:24:35.498 kid1| 24,6| SBuf.cc(153) assign: SBuf2135 from c-string, n=4294967295) 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2135 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 17 for SBuf2135 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(956) cow: SBuf2135 new size:17 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2135 new size: 17 2017/08/11 00:24:35.498 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x8321306c0 id=blob662 reserveSize=17 2017/08/11 00:24:35.498 kid1| 24,8| MemBlob.cc(102) memAlloc: blob662 memAlloc: requested=17, received=40 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2135 new store capacity: 40 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2136 created 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2136 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 8 for SBuf2136 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(956) cow: SBuf2136 new size:8 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2136 new size: 8 2017/08/11 00:24:35.498 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130a50 id=blob663 reserveSize=8 2017/08/11 00:24:35.498 kid1| 24,8| MemBlob.cc(102) memAlloc: blob663 memAlloc: requested=8, received=40 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2136 new store capacity: 40 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 17 for SBuf2136 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2136 not growing 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2136 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 17 for SBuf2136 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(956) cow: SBuf2136 new size:42 2017/08/11 00:24:35.498 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2136 new size: 42 2017/08/11 00:24:35.498 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130ab0 id=blob664 reserveSize=42 2017/08/11 00:24:35.498 kid1| 24,8| MemBlob.cc(102) memAlloc: blob664 memAlloc: requested=42, received=128 2017/08/11 00:24:35.498 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x832130a50 id=blob663 capacity=40 size=25 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2136 new store capacity: 128 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 17 for SBuf2136 2017/08/11 00:24:35.498 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2136 not growing 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2136 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 4 for SBuf2136 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2136 not growing 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 0 for SBuf2136 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2136 not growing 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2128 from SBuf2136 2017/08/11 00:24:35.499 kid1| 33,5| client_side.cc(3232) clientParseRequests: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33: attempting to parse 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 1 for SBuf2128 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2128 not growing 2017/08/11 00:24:35.499 kid1| 74,5| HttpParser.cc(37) reset: Request buffer is CONNECT 185.89.12.132:443 HTTP/1.1 Host: 185.89.12.132:443 2017/08/11 00:24:35.499 kid1| 74,5| HttpParser.cc(47) parseRequestFirstLine: parsing possible request: CONNECT 185.89.12.132:443 HTTP/1.1 Host: 185.89.12.132:443 2017/08/11 00:24:35.499 kid1| 74,5| HttpParser.cc(257) HttpParserParseReqLine: Parser: retval 1: from 0->35: method 0->6; url 8->24; version 26->33 (1/1) 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2137 created 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2131 from SBuf2137 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2137 destructed 2017/08/11 00:24:35.499 kid1| 33,3| client_side.cc(2277) parseHttpRequest: parseHttpRequest: req_hdr = {Host: 185.89.12.132:443 } 2017/08/11 00:24:35.499 kid1| 33,3| client_side.cc(2281) parseHttpRequest: parseHttpRequest: end = { } 2017/08/11 00:24:35.499 kid1| 33,3| client_side.cc(2285) parseHttpRequest: parseHttpRequest: prefix_sz = 63, req_line_sz = 36 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x802e16b98 2017/08/11 00:24:35.499 kid1| 93,5| AsyncJob.cc(34) AsyncJob: AsyncJob constructed, this=0x802e16ce0 type=ClientHttpRequest [job210] 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=4 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2138 created 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x8321a9818 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x83216c418 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=1 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x8320d2818 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8320d2818=1 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x8320d2698 2017/08/11 00:24:35.499 kid1| 87,3| clientStream.cc(144) clientStreamInsertHead: clientStreamInsertHead: Inserted node 0x8320d2698 with data 0x8321aa890 after head 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8320d2698=1 2017/08/11 00:24:35.499 kid1| 33,5| client_side.cc(2301) parseHttpRequest: parseHttpRequest: Request Header is Host: 185.89.12.132:443 2017/08/11 00:24:35.499 kid1| 33,5| client_side.cc(2322) parseHttpRequest: Prepare absolute URL from intercept 2017/08/11 00:24:35.499 kid1| 33,5| client_side.cc(2361) parseHttpRequest: parseHttpRequest: Complete request received 2017/08/11 00:24:35.499 kid1| 11,2| client_side.cc(2364) parseHttpRequest: HTTP Client local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 2017/08/11 00:24:35.499 kid1| 11,2| client_side.cc(2365) parseHttpRequest: HTTP Client REQUEST: --------- CONNECT 185.89.12.132:443 HTTP/1.1 Host: 185.89.12.132:443 ---------- 2017/08/11 00:24:35.499 kid1| 33,5| client_side.cc(3253) clientParseRequests: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33: done parsing a request 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=2 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=3 2017/08/11 00:24:35.499 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall clientLifetimeTimeout constructed, this=0x803190360 [call1691] 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=4 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=3 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=2 2017/08/11 00:24:35.499 kid1| 5,3| comm.cc(553) commSetConnTimeout: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 timeout 86400 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.499 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.499 kid1| 23,3| url.cc(371) urlParse: urlParse: Split URL '185.89.12.132:443' into proto='', host='185.89.12.132', port='443', path='' 2017/08/11 00:24:35.499 kid1| 55,7| HttpHeader.cc(446) HttpHeader: init-ing hdr: 0x832216318 owner: 2 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2139 created 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2140 created 2017/08/11 00:24:35.499 kid1| 93,7| HttpRequest.cc(47) HttpRequest: constructed, this=0x832216300 id=117 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2141 created 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2140 from SBuf2141 2017/08/11 00:24:35.499 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2141 destructed 2017/08/11 00:24:35.499 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2139 from SBuf2131 2017/08/11 00:24:35.499 kid1| 23,3| ../src/HttpRequest.h(82) SetHost: HttpRequest::SetHost() given IP: 185.89.12.132 2017/08/11 00:24:35.499 kid1| 55,7| HttpHeader.cc(643) parse: parsing hdr: (0x832216318) Host: 185.89.12.132:443 2017/08/11 00:24:35.499 kid1| 55,9| HttpHeader.cc(1702) parse: parsing HttpHeaderEntry: near 'Host: 185.89.12.132:443' 2017/08/11 00:24:35.499 kid1| 55,9| HttpHeader.cc(1744) parse: parsed HttpHeaderEntry: 'Host: 185.89.12.132:443' 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x8320afd40: 'Host : 185.89.12.132:443 2017/08/11 00:24:35.500 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x832216318 adding entry: 29 at 0 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 62 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 29 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2142 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 13 for SBuf2142 2017/08/11 00:24:35.500 kid1| 24,8| SBuf.cc(956) cow: SBuf2142 new size:13 2017/08/11 00:24:35.500 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2142 new size: 13 2017/08/11 00:24:35.500 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130bd0 id=blob665 reserveSize=13 2017/08/11 00:24:35.500 kid1| 24,8| MemBlob.cc(102) memAlloc: blob665 memAlloc: requested=13, received=40 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2142 new store capacity: 40 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 6 for SBuf2142 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2142 not growing 2017/08/11 00:24:35.500 kid1| 33,5| client_side.cc(2689) clientProcessRequest: URL domain 185.89.12.132:443 overrides header Host: 185.89.12.132:443 2017/08/11 00:24:35.500 kid1| 55,8| HttpHeader.cc(954) delById: 0x832216318 del-by-id 29 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8320afd40: 'Host: 185.89.12.132:443' 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 1 for SBuf2142 2017/08/11 00:24:35.500 kid1| 24,7| SBuf.cc(200) rawSpace: SBuf2142 not growing 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x8320afd40: 'Host : 185.89.12.132:443 2017/08/11 00:24:35.500 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x832216318 adding entry: 29 at 1 2017/08/11 00:24:35.500 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2142 destructed 2017/08/11 00:24:35.500 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x832130bd0 id=blob665 capacity=40 size=18 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=5 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=6 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=5 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=6 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=5 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=6 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=5 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 62 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 62 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 25 2017/08/11 00:24:35.500 kid1| 33,3| client_side.cc(890) clientSetKeepaliveFlag: http_ver = HTTP/1.1 2017/08/11 00:24:35.500 kid1| 33,3| client_side.cc(891) clientSetKeepaliveFlag: method = CONNECT 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 11 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 49 2017/08/11 00:24:35.500 kid1| 33,3| ../src/client_side.h(96) mayUseConnection: This 0x8321a9818 marked 1 2017/08/11 00:24:35.500 kid1| 24,8| SBuf.cc(521) consume: SBuf2128 consume 63 2017/08/11 00:24:35.500 kid1| 24,8| SBuf.cc(87) SBuf: SBuf2143 created from id SBuf2128 2017/08/11 00:24:35.500 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2143 destructed 2017/08/11 00:24:35.500 kid1| 33,5| client_side.cc(2439) consumeInput: in.buf has 0 unused bytes 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x8031903e8 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=3 2017/08/11 00:24:35.500 kid1| 85,3| client_side_request.cc(130) ClientRequestContext: 0x8031903e8 ClientRequestContext constructed 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.500 kid1| 83,3| client_side_request.cc(1687) doCallouts: Doing calloutContext->hostHeaderVerify() 2017/08/11 00:24:35.500 kid1| 85,3| client_side_request.cc(634) hostHeaderVerify: validate host=185.89.12.132, port=443, portStr=443 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.500 kid1| 14,4| ipcache.cc(493) ipcache_nbgethostbyname: ipcache_nbgethostbyname: Name '185.89.12.132'. 2017/08/11 00:24:35.500 kid1| 14,4| ipcache.cc(802) ipcacheCheckNumeric: ipcacheCheckNumeric: HIT_BYPASS for '185.89.12.132' == 185.89.12.132 2017/08/11 00:24:35.500 kid1| 14,4| ipcache.cc(506) ipcache_nbgethostbyname: ipcache_nbgethostbyname: BYPASS for '185.89.12.132' (already numeric) 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.500 kid1| 85,3| client_side_request.cc(526) hostHeaderIpVerify: validate IP 185.89.12.132:443 possible from Host: 2017/08/11 00:24:35.500 kid1| 83,3| client_side_request.cc(1694) doCallouts: Doing calloutContext->clientAccessCheck() 2017/08/11 00:24:35.500 kid1| 55,9| HttpHeader.cc(1247) has: 0x832216318 lookup for 73 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.500 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x802e17618 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802b76398=1 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=6 2017/08/11 00:24:35.501 kid1| 28,3| Checklist.cc(70) preCheck: 0x802e17618 checking slow rules 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8031903e8=1 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8031903e8 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x802b76398 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking http_access 2017/08/11 00:24:35.501 kid1| 28,5| Checklist.cc(400) bannedAction: Action 'ALLOWED/0' is not banned 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking http_access#1 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking manager 2017/08/11 00:24:35.501 kid1| 28,3| RegexData.cc(51) match: aclRegexData::match: checking '185.89.12.132:443' 2017/08/11 00:24:35.501 kid1| 28,3| RegexData.cc(62) match: aclRegexData::match: looking for '(^cache_object://)' 2017/08/11 00:24:35.501 kid1| 28,3| RegexData.cc(62) match: aclRegexData::match: looking for '(^https?://[^/]+/squid-internal-mgr/)' 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: manager = 0 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: http_access#1 = 0 2017/08/11 00:24:35.501 kid1| 28,5| Checklist.cc(400) bannedAction: Action 'DENIED/0' is not banned 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking http_access#2 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking manager 2017/08/11 00:24:35.501 kid1| 28,3| RegexData.cc(51) match: aclRegexData::match: checking '185.89.12.132:443' 2017/08/11 00:24:35.501 kid1| 28,3| RegexData.cc(62) match: aclRegexData::match: looking for '(^cache_object://)' 2017/08/11 00:24:35.501 kid1| 28,3| RegexData.cc(62) match: aclRegexData::match: looking for '(^https?://[^/]+/squid-internal-mgr/)' 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: manager = 0 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: http_access#2 = 0 2017/08/11 00:24:35.501 kid1| 28,5| Checklist.cc(400) bannedAction: Action 'ALLOWED/0' is not banned 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking http_access#3 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking purge 2017/08/11 00:24:35.501 kid1| 24,8| SBuf.cc(87) SBuf: SBuf2144 created from id SBuf2139 2017/08/11 00:24:35.501 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2144 destructed 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: purge = 0 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: http_access#3 = 0 2017/08/11 00:24:35.501 kid1| 28,5| Checklist.cc(400) bannedAction: Action 'DENIED/0' is not banned 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking http_access#4 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking purge 2017/08/11 00:24:35.501 kid1| 24,8| SBuf.cc(87) SBuf: SBuf2145 created from id SBuf2139 2017/08/11 00:24:35.501 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2145 destructed 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: purge = 0 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: http_access#4 = 0 2017/08/11 00:24:35.501 kid1| 28,5| Checklist.cc(400) bannedAction: Action 'DENIED/0' is not banned 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking http_access#5 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking !Safe_ports 2017/08/11 00:24:35.501 kid1| 28,5| Acl.cc(138) matches: checking Safe_ports 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: Safe_ports = 0 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: !Safe_ports = 1 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: http_access#5 = 1 2017/08/11 00:24:35.501 kid1| 28,3| Acl.cc(158) matches: checked: http_access = 1 2017/08/11 00:24:35.501 kid1| 28,3| Checklist.cc(63) markFinished: 0x802e17618 answer DENIED for match 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802b76398=0 2017/08/11 00:24:35.501 kid1| 28,3| Checklist.cc(163) checkCallback: ACLChecklist::checkCallback: 0x802e17618 answer=DENIED 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8031903e8 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8031903e8=0 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x802e16b98 2017/08/11 00:24:35.501 kid1| 85,2| client_side_request.cc(744) clientAccessCheckDone: The request CONNECT 185.89.12.132:443 is DENIED; last ACL checked: Safe_ports 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.501 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.501 kid1| 28,5| Gadgets.cc(83) aclIsProxyAuth: aclIsProxyAuth: called for Safe_ports 2017/08/11 00:24:35.501 kid1| 28,9| Acl.cc(99) FindByName: ACL::FindByName 'Safe_ports' 2017/08/11 00:24:35.501 kid1| 28,5| Gadgets.cc(88) aclIsProxyAuth: aclIsProxyAuth: returning 0 2017/08/11 00:24:35.501 kid1| 85,5| client_side_request.cc(760) clientAccessCheckDone: Access Denied: 185.89.12.132:443 2017/08/11 00:24:35.501 kid1| 85,5| client_side_request.cc(761) clientAccessCheckDone: AclMatchedName = Safe_ports 2017/08/11 00:24:35.501 kid1| 28,8| Gadgets.cc(51) aclGetDenyInfoPage: got called for Safe_ports 2017/08/11 00:24:35.502 kid1| 28,8| Gadgets.cc(70) aclGetDenyInfoPage: aclGetDenyInfoPage: no match 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x83209a218 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=7 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=6 2017/08/11 00:24:35.502 kid1| 28,4| FilledChecklist.cc(66) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fffffffd2f0 2017/08/11 00:24:35.502 kid1| 28,4| Checklist.cc(197) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7fffffffd2f0 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=7 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=6 2017/08/11 00:24:35.502 kid1| 28,4| FilledChecklist.cc(66) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fffffffd150 2017/08/11 00:24:35.502 kid1| 28,4| Checklist.cc(197) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7fffffffd150 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 85,5| client_side_request.cc(1422) sslBumpAccessCheck: SslBump already decided (3), ignoring ssl_bump for 0x832110118 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.502 kid1| 83,3| client_side_request.cc(1531) sslBumpNeed: sslBump required: peek 2017/08/11 00:24:35.502 kid1| 73,3| HttpRequest.cc(692) storeId: sent back canonicalUrl:185.89.12.132:443 2017/08/11 00:24:35.502 kid1| 20,3| store.cc(805) storeCreatePureEntry: storeCreateEntry: '185.89.12.132:443' 2017/08/11 00:24:35.502 kid1| 20,5| store.cc(370) StoreEntry: StoreEntry constructed, this=0x803190440 2017/08/11 00:24:35.502 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2146 created 2017/08/11 00:24:35.502 kid1| 19,9| stmem.cc(375) mem_hdr: 0x8320c4ea0 hi: 0 2017/08/11 00:24:35.502 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2147 created 2017/08/11 00:24:35.502 kid1| 20,3| MemObject.cc(97) MemObject: new MemObject 0x8320c4e80 2017/08/11 00:24:35.502 kid1| 55,7| HttpHeader.cc(446) HttpHeader: init-ing hdr: 0x8321f4b58 owner: 3 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x83212c3d8 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1247) has: 0x8321f4b58 lookup for 11 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1247) has: 0x8321f4b58 lookup for 49 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1247) has: 0x8321f4b58 lookup for 26 2017/08/11 00:24:35.502 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2146 from SBuf2139 2017/08/11 00:24:35.502 kid1| 20,3| store.cc(499) setReleaseFlag: StoreEntry::setReleaseFlag: '[null_store_key]' 2017/08/11 00:24:35.502 kid1| 20,3| store_key_md5.cc(89) storeKeyPrivate: storeKeyPrivate: CONNECT 185.89.12.132:443 2017/08/11 00:24:35.502 kid1| 20,3| store.cc(447) hashInsert: StoreEntry::hashInsert: Inserting Entry e:=XI/0x803190440*0 key '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.502 kid1| 20,3| store.cc(483) lock: storeCreateEntry locked key 08D19C5DFA9A8243A8EE6FA30CDA1B5F e:=XIV/0x803190440*1 2017/08/11 00:24:35.502 kid1| 83,3| client_side_request.cc(1531) sslBumpNeed: sslBump required: client-first 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x8031904c8 2017/08/11 00:24:35.502 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2148 created 2017/08/11 00:24:35.502 kid1| 33,4| ServerBump.cc(27) ServerBump: will peek at 185.89.12.132:443 2017/08/11 00:24:35.502 kid1| 20,3| store.cc(483) lock: Ssl::ServerBump locked key 08D19C5DFA9A8243A8EE6FA30CDA1B5F e:=XIV/0x803190440*2 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x8320a88f8 2017/08/11 00:24:35.502 kid1| 4,4| errorpage.cc(602) errorAppendEntry: Creating an error page for entry 0x803190440 with errorstate 0x83209a218 page id 1 2017/08/11 00:24:35.502 kid1| 55,7| HttpHeader.cc(446) HttpHeader: init-ing hdr: 0x8321f4c98 owner: 3 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x83212c318 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1247) has: 0x8321f4c98 lookup for 11 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1247) has: 0x8321f4c98 lookup for 49 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1247) has: 0x8321f4c98 lookup for 26 2017/08/11 00:24:35.502 kid1| 55,9| HttpHeader.cc(1067) getList: 0x832216318 joining for id 3 2017/08/11 00:24:35.502 kid1| 4,2| errorpage.cc(1261) BuildContent: No existing error page language negotiated for ERR_ACCESS_DENIED. Using default error file. 2017/08/11 00:24:35.502 kid1| 45,9| cbdata.cc(299) cbdataInternalAlloc: Allocating 0x83212c358 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%l --> '/* * Copyright © 1996-2016 The Squid Software Foundation and contributors * * Squid software is distributed under GPLv2+ license and includes * contributions from numerous individuals and organizations. * Please see the COPYING and CONTRIBUTORS files for details. */ /* Stylesheet for Squid Error pages Adapted from design by Free CSS Templates http://www.freecsstemplates.org Released for free under a Creative Commons Attribution 2.5 License */ /* Page basics */ * { font-family: verdana, sans-serif; } html body { margin: 0; padding: 0; background: #efefef; font-size: 12px; color: #1e1e1e; } /* Page displayed title area */ #titles { margin-left: 15px; padding: 10px; padding-left: 100px; background: url('/squid-internal-static/icons/SN.png') no-repeat left; } /* initial title */ #titles h1 { color: #000000; } #titles h2 { color: #000000; } /* special event: FTP success page titles */ #titles ftpsuccess { background-color:#00ff00; width:100%; } /* Page displayed body content area */ #content { padding: 10px; background: #ffffff; } /* General text */ p { } /* error brief description */ #error p { } /* some data which may have caused the problem */ #data { } /* the error message received from the system or other software */ #sysmsg { } pre { font-family:sans-serif; } /* special event: FTP / Gopher directory listing */ #dirmsg { font-family: courier; color: black; font-size: 10pt; } #dirlisting { margin-left: 2%; margin-right: 2%; } #dirlisting tr.entry td.icon,td.filename,td.size,td.date { border-bottom: groove; } #dirlisting td.size { width: 50px; text-align: right; padding-right: 5px; } /* horizontal lines */ hr { margin: 0; } /* page displayed footer area */ #footer { font-size: 9px; padding-left: 10px; } ' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%; --> '%;' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%c --> 'ERR_ACCESS_DENIED' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%U --> 'https://185.89.12.132/*' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%U --> 'https://185.89.12.132/*' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%w --> 'root@insatcom-v.ru' 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(817) packInto: 0x832216318 into 0x7fffffffcd78 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%W --> '?subject=CacheErrorInfo%20-%20ERR_ACCESS_DENIED&body=CacheHost%3A%20reestr-proxy%0D%0AErrPage%3A%20ERR_ACCESS_DENIED%0D%0AErr%3A%20%5Bnone%5D%0D%0ATimeStamp%3A%20Thu,%2010%20Aug%202017%2021%3A24%3A35%20GMT%0D%0A%0D%0AClientIP%3A%20EEE.FFF.GGG.HHHH%0D%0A%0D%0AHTTP%20Request%3A%0D%0ACONNECT%20%2F%20HTTP%2F1.1%0AHost%3A%20185.89.12.132%3A443%0D%0A%0D%0A%0D%0A' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%w --> 'root@insatcom-v.ru' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%T --> 'Thu, 10 Aug 2017 21:24:35 GMT' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%h --> 'reestr-proxy' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%s --> 'squid/3.5.23' 2017/08/11 00:24:35.503 kid1| 4,3| errorpage.cc(1100) Convert: errorConvert: %%c --> 'ERR_ACCESS_DENIED' 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x83212c380: 'Server : squid/3.5.23 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 56 at 0 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x8320afd00: 'Mime-Version : 1.0 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 42 at 1 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x8320afd80: 'Date : Thu, 10 Aug 2017 21:24:35 GMT 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 23 at 2 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x83212c2c0: 'Content-Type : text/html;charset=utf-8 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 20 at 3 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x8320cca40: 'Content-Length : 3470 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 16 at 4 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x8320afe00: 'X-Squid-Error : ERR_ACCESS_DENIED 0 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 75 at 5 2017/08/11 00:24:35.503 kid1| 55,8| HttpHeader.cc(954) delById: 0x8321f4c98 del-by-id 67 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x83212c400: 'Vary : Accept-Language 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 67 at 6 2017/08/11 00:24:35.503 kid1| 55,9| HttpHeader.cc(1645) HttpHeaderEntry: created HttpHeaderEntry 0x83212c440: 'Content-Language : en 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(1027) addEntry: 0x8321f4c98 adding entry: 15 at 7 2017/08/11 00:24:35.503 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x83212c318 2017/08/11 00:24:35.503 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x83212c318 2017/08/11 00:24:35.503 kid1| 11,5| HttpRequest.cc(472) detailError: current error details: 1/0 2017/08/11 00:24:35.503 kid1| 20,3| store.cc(483) lock: StoreEntry::storeErrorResponse locked key 08D19C5DFA9A8243A8EE6FA30CDA1B5F e:=XIV/0x803190440*3 2017/08/11 00:24:35.503 kid1| 20,3| store.cc(1906) replaceHttpReply: StoreEntry::replaceHttpReply: 185.89.12.132:443 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x8321f4b58 owner: 3 2017/08/11 00:24:35.503 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x83212c3d8 2017/08/11 00:24:35.503 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x83212c3d8 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x8321f4b58 owner: 3 2017/08/11 00:24:35.503 kid1| 57,9| StatusLine.cc(64) packInto: packing sline 0x8321f4d38 using 0x7fffffffcfa0: 2017/08/11 00:24:35.503 kid1| 57,9| StatusLine.cc(65) packInto: FORMAT=HTTP/%d.%d %3d %s 2017/08/11 00:24:35.503 kid1| 57,9| StatusLine.cc(66) packInto: HTTP/1.1 403 Forbidden 2017/08/11 00:24:35.503 kid1| 20,5| store.cc(860) write: storeWrite: writing 24 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.503 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 0 len 24 2017/08/11 00:24:35.503 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [0,24) object end 0 2017/08/11 00:24:35.503 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 0 2017/08/11 00:24:35.503 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 24 2017/08/11 00:24:35.503 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 24 2017/08/11 00:24:35.503 kid1| 55,7| HttpHeader.cc(817) packInto: 0x8321f4c98 into 0x7fffffffcfa0 2017/08/11 00:24:35.503 kid1| 20,5| store.cc(860) write: storeWrite: writing 6 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.503 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 24 len 6 2017/08/11 00:24:35.503 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [24,30) object end 24 2017/08/11 00:24:35.503 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 24 2017/08/11 00:24:35.503 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 30 2017/08/11 00:24:35.503 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 30 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 30 len 2 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [30,32) object end 30 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 30 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 32 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 32 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 12 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 32 len 12 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [32,44) object end 32 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 32 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 44 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 44 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 44 len 2 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [44,46) object end 44 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 44 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 46 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 46 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 12 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 46 len 12 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [46,58) object end 46 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 46 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 58 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 58 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 58 len 2 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [58,60) object end 58 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 58 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 60 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 60 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 3 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 60 len 3 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [60,63) object end 60 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 60 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 63 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 63 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 63 len 2 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [63,65) object end 63 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 63 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 65 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 65 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 4 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 65 len 4 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [65,69) object end 65 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 65 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 69 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 69 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 69 len 2 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [69,71) object end 69 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 69 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 71 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 71 2017/08/11 00:24:35.504 kid1| 20,5| store.cc(860) write: storeWrite: writing 29 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.504 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 71 len 29 2017/08/11 00:24:35.504 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [71,100) object end 71 2017/08/11 00:24:35.504 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 71 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 100 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 100 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 100 len 2 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [100,102) object end 100 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 100 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 102 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 102 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 12 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 102 len 12 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [102,114) object end 102 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 102 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 114 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 114 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 114 len 2 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [114,116) object end 114 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 114 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 116 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 116 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 23 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 116 len 23 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [116,139) object end 116 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 116 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 139 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 139 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 139 len 2 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [139,141) object end 139 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 139 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 141 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 141 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 14 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 141 len 14 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [141,155) object end 141 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 141 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 155 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 155 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 155 len 2 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [155,157) object end 155 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 155 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 157 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 157 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 4 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 157 len 4 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [157,161) object end 157 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 157 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 161 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 161 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 161 len 2 2017/08/11 00:24:35.505 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [161,163) object end 161 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 161 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 163 2017/08/11 00:24:35.505 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 163 2017/08/11 00:24:35.505 kid1| 20,5| store.cc(860) write: storeWrite: writing 13 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.505 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 163 len 13 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [163,176) object end 163 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 163 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 176 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 176 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 176 len 2 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [176,178) object end 176 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 176 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 178 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 178 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 19 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 178 len 19 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [178,197) object end 178 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 178 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 197 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 197 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 197 len 2 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [197,199) object end 197 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 197 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 199 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 199 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 4 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 199 len 4 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [199,203) object end 199 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 199 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 203 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 203 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 203 len 2 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [203,205) object end 203 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 203 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 205 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 205 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 15 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 205 len 15 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [205,220) object end 205 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 205 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 220 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 220 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 220 len 2 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [220,222) object end 220 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 220 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 222 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 222 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 16 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 222 len 16 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [222,238) object end 222 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 222 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 238 2017/08/11 00:24:35.506 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 238 2017/08/11 00:24:35.506 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.506 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 238 len 2 2017/08/11 00:24:35.506 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [238,240) object end 238 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 238 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 240 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 240 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.507 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 240 len 2 2017/08/11 00:24:35.507 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [240,242) object end 240 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 240 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 242 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 242 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.507 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 242 len 2 2017/08/11 00:24:35.507 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [242,244) object end 242 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 242 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 244 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 244 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(860) write: storeWrite: writing 2 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.507 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 244 len 2 2017/08/11 00:24:35.507 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [244,246) object end 244 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 244 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 246 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 246 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(860) write: storeWrite: writing 3470 bytes for '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.507 kid1| 19,6| MemObject.cc(151) write: memWrite: offset 246 len 3470 2017/08/11 00:24:35.507 kid1| 19,6| stmem.cc(344) write: mem_hdr::write: 0x8320c4ea0 [246,3716) object end 246 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(124) writeAvailable: 0x8320c4ea0 hi: 246 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(131) writeAvailable: 0x8320c4ea0 hi: 3716 2017/08/11 00:24:35.507 kid1| 19,9| stmem.cc(132) writeAvailable: 0x8320c4ea0 hi: 3716 2017/08/11 00:24:35.507 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable 2017/08/11 00:24:35.507 kid1| 20,3| store_swapout.cc(381) mayStartSwapOut: not cachable 2017/08/11 00:24:35.507 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable 2017/08/11 00:24:35.507 kid1| 20,7| store_dir.cc(821) memoryOut: keepInLocalMemory: 0 2017/08/11 00:24:35.507 kid1| 88,7| store.cc(2009) trimMemory: e:=XIV/0x803190440*3 inmem_lo=0 2017/08/11 00:24:35.507 kid1| 90,3| store_client.cc(732) invokeHandlers: InvokeHandlers: 08D19C5DFA9A8243A8EE6FA30CDA1B5F 2017/08/11 00:24:35.507 kid1| 90,3| store_client.cc(738) invokeHandlers: StoreEntry::InvokeHandlers: checking client #0 2017/08/11 00:24:35.507 kid1| 20,3| store.cc(1079) complete: storeComplete: '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.507 kid1| 20,3| store.cc(1368) validLength: storeEntryValidLength: Checking '08D19C5DFA9A8243A8EE6FA30CDA1B5F' 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(1370) validLength: storeEntryValidLength: object_len = 3716 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(1371) validLength: storeEntryValidLength: hdr_sz = 246 2017/08/11 00:24:35.507 kid1| 20,5| store.cc(1372) validLength: storeEntryValidLength: content_length = 3470 2017/08/11 00:24:35.507 kid1| 20,3| store_swapout.cc(356) mayStartSwapOut: already rejected 2017/08/11 00:24:35.507 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable 2017/08/11 00:24:35.507 kid1| 20,7| store_dir.cc(821) memoryOut: keepInLocalMemory: 0 2017/08/11 00:24:35.507 kid1| 88,7| store.cc(2009) trimMemory: e:=sXIV/0x803190440*3 inmem_lo=0 2017/08/11 00:24:35.507 kid1| 90,3| store_client.cc(732) invokeHandlers: InvokeHandlers: 08D19C5DFA9A8243A8EE6FA30CDA1B5F 2017/08/11 00:24:35.507 kid1| 90,3| store_client.cc(738) invokeHandlers: StoreEntry::InvokeHandlers: checking client #0 2017/08/11 00:24:35.507 kid1| 20,3| store.cc(521) unlock: StoreEntry::storeErrorResponse unlocking key 08D19C5DFA9A8243A8EE6FA30CDA1B5F e:=sXINV/0x803190440*3 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x83209a218 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x83209a218 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.507 kid1| 20,3| store.cc(521) unlock: ClientHttpRequest::doCallouts+sslBumpNeeded unlocking key 08D19C5DFA9A8243A8EE6FA30CDA1B5F e:=sXINV/0x803190440*2 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=2 2017/08/11 00:24:35.507 kid1| 85,3| client_side_request.cc(115) ~ClientRequestContext: 0x8031903e8 ClientRequestContext destructed 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8031903e8 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8031903e8 2017/08/11 00:24:35.507 kid1| 83,3| client_side_request.cc(1831) doCallouts: calling processRequest() 2017/08/11 00:24:35.507 kid1| 85,4| client_side_request.cc(1494) processRequest: CONNECT 185.89.12.132:443 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.507 kid1| 85,5| client_side_request.cc(1577) sslBumpStart: Confirming client-first-bumped CONNECT tunnel on FD local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 2017/08/11 00:24:35.507 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=3 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=4 2017/08/11 00:24:35.508 kid1| 85,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ClientSocketContext::sslBumpEstablish constructed, this=0x8320d2780 [call1692] 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802e16b98=5 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=4 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=3 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.508 kid1| 85,5| AsyncCall.cc(93) ScheduleCall: client_side_request.cc(1587) will call ClientSocketContext::sslBumpEstablish(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33, data=0x802e16b98) [call1692] 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=5 2017/08/11 00:24:35.508 kid1| 28,4| FilledChecklist.cc(66) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x802e17618 2017/08/11 00:24:35.508 kid1| 28,4| Checklist.cc(197) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x802e17618 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x802e17618 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x802e17618 2017/08/11 00:24:35.508 kid1| 33,3| client_side.cc(3265) clientParseRequests: Not parsing new requests, as this request may need the connection 2017/08/11 00:24:35.508 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2136 destructed 2017/08/11 00:24:35.508 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2135 destructed 2017/08/11 00:24:35.508 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8321306c0 id=blob662 capacity=40 size=17 2017/08/11 00:24:35.508 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x802d98d18 owner: 2 2017/08/11 00:24:35.508 kid1| 93,7| HttpRequest.cc(55) ~HttpRequest: destructed, this=0x802d98d00 2017/08/11 00:24:35.508 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2133 destructed 2017/08/11 00:24:35.508 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2132 destructed 2017/08/11 00:24:35.508 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x802d98d18 owner: 2 2017/08/11 00:24:35.508 kid1| 28,4| FilledChecklist.cc(66) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x802e16f18 2017/08/11 00:24:35.508 kid1| 28,4| Checklist.cc(197) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x802e16f18 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x802e16f18 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x802e16f18 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.508 kid1| 93,5| AsyncJob.cc(152) callEnd: Http::Server status out: [ job209] 2017/08/11 00:24:35.508 kid1| 93,5| AsyncCallQueue.cc(57) fireNext: leaving AsyncJob::start() 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=4 2017/08/11 00:24:35.508 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering commStartSslClose(FD 74) 2017/08/11 00:24:35.508 kid1| 5,4| AsyncCall.cc(38) make: make call commStartSslClose [call1685] 2017/08/11 00:24:35.508 kid1| 83,5| bio.cc(95) write: FD 74 wrote 31 <= 31 2017/08/11 00:24:35.508 kid1| 83,7| bio.cc(168) stateChanged: FD 74 now: 0x4008 SSLOK (SSL negotiation finished successfully) 2017/08/11 00:24:35.508 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving commStartSslClose(FD 74) 2017/08/11 00:24:35.508 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x83210f218) 2017/08/11 00:24:35.508 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::connStateClosed [call1601] 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job191] 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 93,4| AsyncJob.cc(55) deleteThis: Http::Server will NOT delete in-call job, reason: ConnStateData::connStateClosed 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 93,5| AsyncJob.cc(137) callEnd: ConnStateData::connStateClosed(FD -1, data=0x83210f218) ends job [stopped, reason:ConnStateData::connStateClosed job191] 2017/08/11 00:24:35.508 kid1| 33,2| client_side.cc(832) swanSong: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 flags=33 2017/08/11 00:24:35.508 kid1| 33,3| client_side.cc(5136) unpinConnection: 2017/08/11 00:24:35.508 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1963 destructed 2017/08/11 00:24:35.508 kid1| 33,3| client_side.cc(863) ~ConnStateData: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52242 flags=33 2017/08/11 00:24:35.508 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f218 2017/08/11 00:24:35.508 kid1| 33,4| ServerBump.cc(44) ~ServerBump: destroying 2017/08/11 00:24:35.508 kid1| 33,4| ServerBump.cc(46) ~ServerBump: e:=sXINV/0x80318f560*1 2017/08/11 00:24:35.508 kid1| 90,3| store_client.cc(664) storeUnregister: storeUnregister: called for '2AA92E43789F0881470061A0E3F894E2' 2017/08/11 00:24:35.508 kid1| 20,3| store_swapout.cc(356) mayStartSwapOut: already rejected 2017/08/11 00:24:35.508 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable 2017/08/11 00:24:35.508 kid1| 20,7| store_dir.cc(821) memoryOut: keepInLocalMemory: 0 2017/08/11 00:24:35.509 kid1| 19,8| stmem.cc(83) freeDataUpto: 0x8320c2620 up to 3717 2017/08/11 00:24:35.509 kid1| 88,7| store.cc(2009) trimMemory: e:=sXINV/0x80318f560*1 inmem_lo=3717 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8320a9938 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8320a9938 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(483) lock: storeUnregister locked key 2AA92E43789F0881470061A0E3F894E2 e:=sXINV/0x80318f560*2 2017/08/11 00:24:35.509 kid1| 90,3| store_client.cc(758) storePendingNClients: storePendingNClients: returning 0 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(521) unlock: storeUnregister unlocking key 2AA92E43789F0881470061A0E3F894E2 e:=sXINV/0x80318f560*2 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(521) unlock: Ssl::ServerBump unlocking key 2AA92E43789F0881470061A0E3F894E2 e:=sXINV/0x80318f560*1 2017/08/11 00:24:35.509 kid1| 90,3| store_client.cc(758) storePendingNClients: storePendingNClients: returning 0 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(1270) release: releasing e:=sXINV/0x80318f560*0 2AA92E43789F0881470061A0E3F894E2 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(402) destroyMemObject: destroyMemObject 0x8320c2600 2017/08/11 00:24:35.509 kid1| 20,3| MemObject.cc(110) ~MemObject: del MemObject 0x8320c2600 2017/08/11 00:24:35.509 kid1| ctx: enter level 0: '185.89.12.132:443' 2017/08/11 00:24:35.509 kid1| 19,9| stmem.cc(63) freeContent: 0x8320c2620 hi: 0 2017/08/11 00:24:35.509 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x832079ed8 owner: 3 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8031fd480: 'Server: squid/3.5.23' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8320afc40: 'Mime-Version: 1.0' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8320af6c0: 'Date: Thu, 10 Aug 2017 21:24:35 GMT' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83209be00: 'Content-Type: text/html;charset=utf-8' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83209b100: 'Content-Length: 3470' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8320c5b80: 'X-Squid-Error: ERR_ACCESS_DENIED 0' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83209b5c0: 'Vary: Accept-Language' 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8320cc040: 'Content-Language: en' 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8320af9d8 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8320af9d8 2017/08/11 00:24:35.509 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x832079ed8 owner: 3 2017/08/11 00:24:35.509 kid1| ctx: exit level 0 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1991 destructed 2017/08/11 00:24:35.509 kid1| 19,9| stmem.cc(63) freeContent: 0x8320c2620 hi: 0 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1990 destructed 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(420) destroyStoreEntry: destroyStoreEntry: destroying 0x80318f568 2017/08/11 00:24:35.509 kid1| 20,3| store.cc(402) destroyMemObject: destroyMemObject 0x0 2017/08/11 00:24:35.509 kid1| 20,5| store.cc(375) ~StoreEntry: StoreEntry destructed, this=0x80318f560 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1992 destructed 2017/08/11 00:24:35.509 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x802d97f18 owner: 2 2017/08/11 00:24:35.509 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8031fd4c0: 'Host: 185.89.12.132:443' 2017/08/11 00:24:35.509 kid1| 93,7| HttpRequest.cc(55) ~HttpRequest: destructed, this=0x802d97f00 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=2 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1984 destructed 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1983 destructed 2017/08/11 00:24:35.509 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x802d97f18 owner: 2 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x80318f3b8 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x80318f3b8 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1962 destructed 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1961 destructed 2017/08/11 00:24:35.509 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320a3e00 id=blob618 capacity=40 size=13 2017/08/11 00:24:35.509 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1960 destructed 2017/08/11 00:24:35.509 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8321309c0 id=blob660 capacity=4096 size=0 2017/08/11 00:24:35.509 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x83210f3e0 type=Http::Server [job191] 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x83210f218 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(333) cbdataInternalFree: 0x83210f218 has 2 locks, not freeing 2017/08/11 00:24:35.509 kid1| 93,6| AsyncJob.cc(147) callEnd: ConnStateData::connStateClosed(FD -1, data=0x83210f218) ended 0x83210f3e0 2017/08/11 00:24:35.509 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::connStateClosed(FD -1, data=0x83210f218) 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=1 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f218=0 2017/08/11 00:24:35.509 kid1| 45,9| cbdata.cc(449) cbdataInternalUnlock: Freeing 0x83210f218 2017/08/11 00:24:35.509 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering comm_close_complete(FD 74) 2017/08/11 00:24:35.509 kid1| 5,4| AsyncCall.cc(38) make: make call comm_close_complete [call1686] 2017/08/11 00:24:35.510 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1996 destructed 2017/08/11 00:24:35.510 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x832093130 id=blob644 capacity=1024 size=517 2017/08/11 00:24:35.510 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1995 destructed 2017/08/11 00:24:35.510 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320a2600 id=blob645 capacity=40 size=32 2017/08/11 00:24:35.510 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1994 destructed 2017/08/11 00:24:35.510 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320c9500 id=blob647 capacity=40 size=21 2017/08/11 00:24:35.510 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1993 destructed 2017/08/11 00:24:35.510 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320c82a0 id=blob646 capacity=40 size=12 2017/08/11 00:24:35.510 kid1| 83,7| bio.cc(83) ~Bio: Bio destructing, this=0x832038a00 FD 74 2017/08/11 00:24:35.510 kid1| 51,3| fd.cc(93) fd_close: fd_close FD 74 client https start 2017/08/11 00:24:35.510 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 74, type=1, handler=0, client_data=0x0, timeout=0 2017/08/11 00:24:35.510 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 74, type=2, handler=0, client_data=0x0, timeout=0 2017/08/11 00:24:35.510 kid1| 5,5| AcceptLimiter.cc(55) kick: size=0 2017/08/11 00:24:35.510 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving comm_close_complete(FD 74) 2017/08/11 00:24:35.510 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering commStartSslClose(FD 76) 2017/08/11 00:24:35.510 kid1| 5,4| AsyncCall.cc(38) make: make call commStartSslClose [call1687] 2017/08/11 00:24:35.510 kid1| 83,5| bio.cc(95) write: FD 76 wrote 31 <= 31 2017/08/11 00:24:35.510 kid1| 83,7| bio.cc(168) stateChanged: FD 76 now: 0x4008 SSLOK (SSL negotiation finished successfully) 2017/08/11 00:24:35.510 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving commStartSslClose(FD 76) 2017/08/11 00:24:35.510 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x83210f498) 2017/08/11 00:24:35.510 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::connStateClosed [call1613] 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job194] 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 93,4| AsyncJob.cc(55) deleteThis: Http::Server will NOT delete in-call job, reason: ConnStateData::connStateClosed 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 93,5| AsyncJob.cc(137) callEnd: ConnStateData::connStateClosed(FD -1, data=0x83210f498) ends job [stopped, reason:ConnStateData::connStateClosed job194] 2017/08/11 00:24:35.510 kid1| 33,2| client_side.cc(832) swanSong: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 flags=33 2017/08/11 00:24:35.510 kid1| 33,3| client_side.cc(5136) unpinConnection: 2017/08/11 00:24:35.510 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2000 destructed 2017/08/11 00:24:35.510 kid1| 33,3| client_side.cc(863) ~ConnStateData: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52243 flags=33 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x83210f498 2017/08/11 00:24:35.510 kid1| 33,4| ServerBump.cc(44) ~ServerBump: destroying 2017/08/11 00:24:35.510 kid1| 33,4| ServerBump.cc(46) ~ServerBump: e:=sXINV/0x80318fb10*1 2017/08/11 00:24:35.510 kid1| 90,3| store_client.cc(664) storeUnregister: storeUnregister: called for '893DB4F3F0E1D92F9A3D947CF0375632' 2017/08/11 00:24:35.510 kid1| 20,3| store_swapout.cc(356) mayStartSwapOut: already rejected 2017/08/11 00:24:35.510 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable 2017/08/11 00:24:35.510 kid1| 20,7| store_dir.cc(821) memoryOut: keepInLocalMemory: 0 2017/08/11 00:24:35.510 kid1| 19,8| stmem.cc(83) freeDataUpto: 0x8320c30a0 up to 3717 2017/08/11 00:24:35.510 kid1| 88,7| store.cc(2009) trimMemory: e:=sXINV/0x80318fb10*1 inmem_lo=3717 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8320a8cb8 2017/08/11 00:24:35.510 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8320a8cb8 2017/08/11 00:24:35.510 kid1| 20,3| store.cc(483) lock: storeUnregister locked key 893DB4F3F0E1D92F9A3D947CF0375632 e:=sXINV/0x80318fb10*2 2017/08/11 00:24:35.510 kid1| 90,3| store_client.cc(758) storePendingNClients: storePendingNClients: returning 0 2017/08/11 00:24:35.510 kid1| 20,3| store.cc(521) unlock: storeUnregister unlocking key 893DB4F3F0E1D92F9A3D947CF0375632 e:=sXINV/0x80318fb10*2 2017/08/11 00:24:35.510 kid1| 20,3| store.cc(521) unlock: Ssl::ServerBump unlocking key 893DB4F3F0E1D92F9A3D947CF0375632 e:=sXINV/0x80318fb10*1 2017/08/11 00:24:35.510 kid1| 90,3| store_client.cc(758) storePendingNClients: storePendingNClients: returning 0 2017/08/11 00:24:35.510 kid1| 20,3| store.cc(1270) release: releasing e:=sXINV/0x80318fb10*0 893DB4F3F0E1D92F9A3D947CF0375632 2017/08/11 00:24:35.510 kid1| 20,3| store.cc(402) destroyMemObject: destroyMemObject 0x8320c3080 2017/08/11 00:24:35.510 kid1| 20,3| MemObject.cc(110) ~MemObject: del MemObject 0x8320c3080 2017/08/11 00:24:35.510 kid1| ctx: enter level 0: '185.89.12.132:443' 2017/08/11 00:24:35.510 kid1| 19,9| stmem.cc(63) freeContent: 0x8320c30a0 hi: 0 2017/08/11 00:24:35.510 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x832078858 owner: 3 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83209b580: 'Server: squid/3.5.23' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83212ce00: 'Mime-Version: 1.0' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83212cd00: 'Date: Thu, 10 Aug 2017 21:24:35 GMT' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83212cc80: 'Content-Type: text/html;charset=utf-8' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83212cdc0: 'Content-Length: 3470' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83212cd40: 'X-Squid-Error: ERR_ACCESS_DENIED 0' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8031fd5c0: 'Vary: Accept-Language' 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x8031fd600: 'Content-Language: en' 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8320af758 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8320af758 2017/08/11 00:24:35.511 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x832078858 owner: 3 2017/08/11 00:24:35.511 kid1| ctx: exit level 0 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2016 destructed 2017/08/11 00:24:35.511 kid1| 19,9| stmem.cc(63) freeContent: 0x8320c30a0 hi: 0 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2015 destructed 2017/08/11 00:24:35.511 kid1| 20,3| store.cc(420) destroyStoreEntry: destroyStoreEntry: destroying 0x80318fb18 2017/08/11 00:24:35.511 kid1| 20,3| store.cc(402) destroyMemObject: destroyMemObject 0x0 2017/08/11 00:24:35.511 kid1| 20,5| store.cc(375) ~StoreEntry: StoreEntry destructed, this=0x80318fb10 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2017 destructed 2017/08/11 00:24:35.511 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x832214018 owner: 2 2017/08/11 00:24:35.511 kid1| 55,9| HttpHeader.cc(1651) ~HttpHeaderEntry: destroying entry 0x83209b200: 'Host: 185.89.12.132:443' 2017/08/11 00:24:35.511 kid1| 93,7| HttpRequest.cc(55) ~HttpRequest: destructed, this=0x832214000 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=2 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2009 destructed 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2008 destructed 2017/08/11 00:24:35.511 kid1| 55,7| HttpHeader.cc(480) clean: cleaning hdr: 0x832214018 owner: 2 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x80318fb98 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x80318fb98 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1999 destructed 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1998 destructed 2017/08/11 00:24:35.511 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320a2b10 id=blob623 capacity=40 size=13 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf1997 destructed 2017/08/11 00:24:35.511 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8320c8de0 id=blob661 capacity=4096 size=0 2017/08/11 00:24:35.511 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x83210f660 type=Http::Server [job194] 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x83210f498 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(333) cbdataInternalFree: 0x83210f498 has 2 locks, not freeing 2017/08/11 00:24:35.511 kid1| 93,6| AsyncJob.cc(147) callEnd: ConnStateData::connStateClosed(FD -1, data=0x83210f498) ended 0x83210f660 2017/08/11 00:24:35.511 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::connStateClosed(FD -1, data=0x83210f498) 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=1 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x83210f498=0 2017/08/11 00:24:35.511 kid1| 45,9| cbdata.cc(449) cbdataInternalUnlock: Freeing 0x83210f498 2017/08/11 00:24:35.511 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering comm_close_complete(FD 76) 2017/08/11 00:24:35.511 kid1| 5,4| AsyncCall.cc(38) make: make call comm_close_complete [call1688] 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2021 destructed 2017/08/11 00:24:35.511 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x832130270 id=blob648 capacity=1024 size=517 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2020 destructed 2017/08/11 00:24:35.511 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x8321302a0 id=blob649 capacity=40 size=32 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2019 destructed 2017/08/11 00:24:35.511 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x832130360 id=blob651 capacity=40 size=21 2017/08/11 00:24:35.511 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2018 destructed 2017/08/11 00:24:35.511 kid1| 24,9| MemBlob.cc(83) ~MemBlob: destructed, this=0x832130300 id=blob650 capacity=40 size=12 2017/08/11 00:24:35.511 kid1| 83,7| bio.cc(83) ~Bio: Bio destructing, this=0x8320c3200 FD 76 2017/08/11 00:24:35.511 kid1| 51,3| fd.cc(93) fd_close: fd_close FD 76 client https start 2017/08/11 00:24:35.511 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 76, type=1, handler=0, client_data=0x0, timeout=0 2017/08/11 00:24:35.511 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 76, type=2, handler=0, client_data=0x0, timeout=0 2017/08/11 00:24:35.511 kid1| 5,5| AcceptLimiter.cc(55) kick: size=0 2017/08/11 00:24:35.511 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving comm_close_complete(FD 76) 2017/08/11 00:24:35.511 kid1| 85,5| AsyncCallQueue.cc(55) fireNext: entering ClientSocketContext::sslBumpEstablish(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33, data=0x802e16b98) 2017/08/11 00:24:35.512 kid1| 85,5| AsyncCall.cc(38) make: make call ClientSocketContext::sslBumpEstablish [call1692] 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x802e16b98 2017/08/11 00:24:35.512 kid1| 85,5| client_side_request.cc(1540) SslBumpEstablish: responded to CONNECT: 0x802e16b98 ? 0 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x802e16b98 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 24,6| SBuf.cc(153) assign: SBuf2129 from c-string, n=4294967295) 2017/08/11 00:24:35.512 kid1| 24,7| SBuf.cc(242) append: from c-string to id SBuf2129 2017/08/11 00:24:35.512 kid1| 24,7| SBuf.cc(193) rawSpace: reserving 13 for SBuf2129 2017/08/11 00:24:35.512 kid1| 24,8| SBuf.cc(956) cow: SBuf2129 new size:13 2017/08/11 00:24:35.512 kid1| 24,8| SBuf.cc(926) reAlloc: SBuf2129 new size: 13 2017/08/11 00:24:35.512 kid1| 24,9| MemBlob.cc(57) MemBlob: constructed, this=0x832130420 id=blob666 reserveSize=13 2017/08/11 00:24:35.512 kid1| 24,8| MemBlob.cc(102) memAlloc: blob666 memAlloc: requested=13, received=40 2017/08/11 00:24:35.512 kid1| 24,7| SBuf.cc(935) reAlloc: SBuf2129 new store capacity: 40 2017/08/11 00:24:35.512 kid1| 33,5| client_side.cc(4268) switchToHttps: converting local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 to SSL 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 87,3| clientStream.cc(202) clientStreamDetach: clientStreamDetach: Detaching node 0x8320d2698 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x8320d2818=2 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8320d2698=0 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8320d2698 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8320d2698 2017/08/11 00:24:35.512 kid1| 87,3| clientStream.cc(287) clientStreamFree: Freeing clientStreamNode 0x8320d2698 2017/08/11 00:24:35.512 kid1| 87,3| clientStream.cc(223) clientStreamDetach: clientStreamDetach: Calling 1 with cbdata 0x83216d4d0 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8320d2818 2017/08/11 00:24:35.512 kid1| 87,3| clientStream.cc(202) clientStreamDetach: clientStreamDetach: Detaching node 0x8320d2818 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8320d2818=1 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8320d2818 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(333) cbdataInternalFree: 0x8320d2818 has 1 locks, not freeing 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x8320d2818=0 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(449) cbdataInternalUnlock: Freeing 0x8320d2818 2017/08/11 00:24:35.512 kid1| 87,3| clientStream.cc(287) clientStreamFree: Freeing clientStreamNode 0x8320d2818 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=2 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x83216c418 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x83216c418 2017/08/11 00:24:35.512 kid1| 33,3| client_side_request.cc(248) ~ClientHttpRequest: httpRequestFree: 185.89.12.132:443 2017/08/11 00:24:35.512 kid1| 33,9| client_side.cc(593) logRequest: clientLogRequest: al.url='185.89.12.132:443' 2017/08/11 00:24:35.512 kid1| 33,9| client_side.cc(603) logRequest: clientLogRequest: http.code='200' 2017/08/11 00:24:35.512 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf2138 from SBuf2139 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=5 2017/08/11 00:24:35.512 kid1| 28,3| Checklist.cc(70) preCheck: 0x7fffffffe200 checking fast ACLs 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x802b76718=1 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x802b76718 2017/08/11 00:24:35.512 kid1| 28,5| Acl.cc(138) matches: checking access_log daemon:/var/log/squid/access.log 2017/08/11 00:24:35.512 kid1| 28,5| Acl.cc(138) matches: checking (access_log daemon:/var/log/squid/access.log line) 2017/08/11 00:24:35.512 kid1| 28,3| Acl.cc(158) matches: checked: (access_log daemon:/var/log/squid/access.log line) = 1 2017/08/11 00:24:35.512 kid1| 28,3| Acl.cc(158) matches: checked: access_log daemon:/var/log/squid/access.log = 1 2017/08/11 00:24:35.512 kid1| 28,3| Checklist.cc(63) markFinished: 0x7fffffffe200 answer ALLOWED for match 2017/08/11 00:24:35.512 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802b76718=0 2017/08/11 00:24:35.512 kid1| 50,3| ModDaemon.cc(172) logfile_mod_daemon_append: logfile_mod_daemon_append: daemon:/var/log/squid/access.log: appending 1 bytes 2017/08/11 00:24:35.512 kid1| 50,3| ModDaemon.cc(176) logfile_mod_daemon_append: logfile_mod_daemon_append: current buffer has 3273 of 32768 bytes before append 2017/08/11 00:24:35.512 kid1| 24,7| SBuf.cc(139) assign: assigning SBuf638 from SBuf6 2017/08/11 00:24:35.512 kid1| 50,3| ModDaemon.cc(172) logfile_mod_daemon_append: logfile_mod_daemon_append: daemon:/var/log/squid/access.log: appending 94 bytes 2017/08/11 00:24:35.512 kid1| 50,3| ModDaemon.cc(176) logfile_mod_daemon_append: logfile_mod_daemon_append: current buffer has 3274 of 32768 bytes before append 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=4 2017/08/11 00:24:35.513 kid1| 28,4| FilledChecklist.cc(66) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fffffffe200 2017/08/11 00:24:35.513 kid1| 28,4| Checklist.cc(197) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7fffffffe200 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCall.cc(26) AsyncCall: The AsyncCall Initiate::noteInitiatorAborted constructed, this=0x8031902f0 [call1693] 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCall.cc(93) ScheduleCall: Initiator.cc(40) will call Initiate::noteInitiatorAborted() [call1693] 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=3 2017/08/11 00:24:35.513 kid1| 24,8| SBuf.cc(124) ~SBuf: SBuf2138 destructed 2017/08/11 00:24:35.513 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x802e16ce0 type=ClientHttpRequest [job210] 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x802e16b98 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(333) cbdataInternalFree: 0x802e16b98 has 2 locks, not freeing 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0x8321a9818 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(338) cbdataInternalFree: Freeing 0x8321a9818 2017/08/11 00:24:35.513 kid1| 33,5| client_side.cc(4236) getSslContextDone: Using static ssl context. 2017/08/11 00:24:35.513 kid1| 83,5| bio.cc(574) squid_bio_ctrl: 0x80318f950 104(6000, 0x7fffffffe43c) 2017/08/11 00:24:35.513 kid1| 83,7| bio.cc(78) Bio: Bio constructed, this=0x8320c4700 FD 82 2017/08/11 00:24:35.513 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2149 created 2017/08/11 00:24:35.513 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2150 created 2017/08/11 00:24:35.513 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2151 created 2017/08/11 00:24:35.513 kid1| 24,8| SBuf.cc(79) SBuf: SBuf2152 created 2017/08/11 00:24:35.513 kid1| 33,5| client_side.cc(3725) httpsCreate: will negotate SSL on local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=4 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=5 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=6 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=7 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=6 2017/08/11 00:24:35.513 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::requestTimeout constructed, this=0x832248280 [call1694] 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x832110118 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=7 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(394) cbdataInternalLock: 0x832110118=8 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=7 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=6 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x832110118=5 2017/08/11 00:24:35.513 kid1| 5,3| comm.cc(553) commSetConnTimeout: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33 timeout 300 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=1 2017/08/11 00:24:35.513 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 82, type=1, handler=0, client_data=0x0, timeout=0 2017/08/11 00:24:35.513 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 82, type=1, handler=1, client_data=0x832110118, timeout=0 2017/08/11 00:24:35.513 kid1| 85,5| AsyncCallQueue.cc(57) fireNext: leaving ClientSocketContext::sslBumpEstablish(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52248 FD 82 flags=33, data=0x802e16b98) 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(426) cbdataInternalUnlock: 0x802e16b98=0 2017/08/11 00:24:35.513 kid1| 45,9| cbdata.cc(449) cbdataInternalUnlock: Freeing 0x802e16b98 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCallQueue.cc(55) fireNext: entering Initiate::noteInitiatorAborted() 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCall.cc(38) make: make call Initiate::noteInitiatorAborted [call1693] 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCall.cc(56) cancel: will not call Initiate::noteInitiatorAborted [call1693] because job gone 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCall.cc(48) make: will not call Initiate::noteInitiatorAborted [call1693] because of job gone 2017/08/11 00:24:35.513 kid1| 93,5| AsyncCallQueue.cc(57) fireNext: leaving Initiate::noteInitiatorAborted() 2017/08/11 00:24:35.513 kid1| 1,9| EventLoop.cc(41) checkEngine: Engine 0x7fffffffe7d0 is idle. 2017/08/11 00:24:35.513 kid1| 1,9| EventLoop.cc(41) checkEngine: Engine 0x7fffffffe7c8 is idle. 2017/08/11 00:24:35.513 kid1| 5,2| TcpAcceptor.cc(220) doAccept: New connection on FD 40 2017/08/11 00:24:35.513 kid1| 5,2| TcpAcceptor.cc(295) acceptNext: connection on local=192.168.2.230:3128 remote=[::] FD 40 flags=41 2017/08/11 00:24:35.513 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 74 HTTP Request 2017/08/11 00:24:35.513 kid1| 89,5| Intercept.cc(401) Lookup: address BEGIN: me/client= 5.144.130.34:80, destination/me= 188.43.36.22:62589 2017/08/11 00:24:35.513 kid1| 89,5| Intercept.cc(187) IpfwInterception: address NAT: local=5.144.130.34:80 remote=188.43.36.22:62589 FD 74 flags=33 2017/08/11 00:24:35.514 kid1| 5,5| TcpAcceptor.cc(287) acceptOne: Listener: local=192.168.2.230:3128 remote=[::] FD 40 flags=41 accepted new connection local=5.144.130.34:80 remote=188.43.36.22:62589 FD 74 flags=33 handler Subscription: 0x83204a540*1 2017/08/11 00:24:35.514 kid1| 5,5| AsyncCall.cc(26) AsyncCall: The AsyncCall httpAccept constructed, this=0x8320d2780 [call1695] 2017/08/11 00:24:35.514 kid1| 5,5| AsyncCall.cc(93) ScheduleCall: TcpAcceptor.cc(317) will call httpAccept(local=5.144.130.34:80 remote=188.43.36.22:62589 FD 74 flags=33, MXID_56) [call1695] 2017/08/11 00:24:35.514 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 40, type=1, handler=1, client_data=0x802f2c658, timeout=0 2017/08/11 00:24:35.514 kid1| 5,2| TcpAcceptor.cc(220) doAccept: New connection on FD 41 2017/08/11 00:24:35.514 kid1| 5,2| TcpAcceptor.cc(295) acceptNext: connection on local=192.168.2.230:3129 remote=[::] FD 41 flags=41 2017/08/11 00:24:35.514 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 76 HTTP Request 2017/08/11 00:24:35.514 kid1| 89,5| Intercept.cc(401) Lookup: address BEGIN: me/client= 185.89.12.132:443, destination/me= EEE.FFF.GGG.HHHH:52249 2017/08/11 00:24:35.514 kid1| 89,5| Intercept.cc(187) IpfwInterception: address NAT: local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52249 FD 76 flags=33 2017/08/11 00:24:35.514 kid1| 5,5| TcpAcceptor.cc(287) acceptOne: Listener: local=192.168.2.230:3129 remote=[::] FD 41 flags=41 accepted new connection local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52249 FD 76 flags=33 handler Subscription: 0x83204a560*1 2017/08/11 00:24:35.514 kid1| 5,5| AsyncCall.cc(26) AsyncCall: The AsyncCall httpsAccept constructed, this=0x8320d2800 [call1696] 2017/08/11 00:24:35.514 kid1| 5,5| AsyncCall.cc(93) ScheduleCall: TcpAcceptor.cc(317) will call httpsAccept(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52249 FD 76 flags=33, MXID_57) [call1696] 2017/08/11 00:24:35.514 kid1| 5,5| ModKqueue.cc(174) SetSelect: FD 41, type=1, handler=1, client_data=0x802f2c578, timeout=0 2017/08/11 00:24:35.514 kid1| 5,3| IoCallback.cc(116) finish: called for local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52244 FD 77 flags=33 (0, 0) 2017/08/11 00:24:35.514 kid1| 33,5| AsyncCall.cc(93) ScheduleCall: IoCallback.cc(135) will call ConnStateData::clientReadRequest(local=185.89.12.132:443 remote=EEE.FFF.GGG.HHHH:52244 FD 77 flags=33, data=0x83210f718) [call1683] 2017/08/11 00:24:35.514 kid1| 83,5| bio.cc(118) read: FD 78 read 5 <= 5 2017/08/11 00:24:35.514 kid1| 83,5| bio.cc(118) read: FD 78 read 134 <= 134 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3RCKEA (SSLv3 read client key exchange A) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3RCV_A (SSLv3 read certificate verify A) 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(118) read: FD 78 read 5 <= 5 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(118) read: FD 78 read 1 <= 1 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(118) read: FD 78 read 5 <= 5 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(118) read: FD 78 read 40 <= 40 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3RFINA (SSLv3 read finished A) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 UNKWN (SSLv3 write session ticket A) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3WCCSA (SSLv3 write change cipher spec A) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3WFINA (SSLv3 write finished A) 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(95) write: FD 78 wrote 242 <= 242 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(574) squid_bio_ctrl: 0x80318fd40 11(0, 0x0) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2001 3FLUSH (SSLv3 flush data) 2017/08/11 00:24:35.515 kid1| 83,5| bio.cc(574) squid_bio_ctrl: 0x80318fd40 7(0, 0x80318f720) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x20 SSLOK (SSL negotiation finished successfully) 2017/08/11 00:24:35.515 kid1| 83,7| bio.cc(168) stateChanged: FD 78 now: 0x2002 SSLOK (SSL negotiation finished successfully) -----BEGIN SSL SESSION PARAMETERS----- MGECAQECAgMDBAIAnAQABDBX/OVEnd+Nx3kPvUOLDEs59tGXbfE187o3fphgTDM2 vvTRtTikwO51F14/TO+JNqWhBgIEWYzPE6IEAgIBLKQCBACmDgQMd3d3LmF2aXRv LnJ1 -----END SSL SESSION PARAMETERS----- Edited August 10, 2017 by snik_1900 Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
mixtery Posted August 11, 2017 Ташовыкажете? Попробуй подмени сертификат без установленного своего у клиента. Забудьте это. Хватит курить манулы двухлетней давности. Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
snik_1900 Posted August 14, 2017 Ташовыкажете? Попробуй подмени сертификат без установленного своего у клиента. Забудьте это. Хватит курить манулы двухлетней давности. А без подмены никак? На шаге step1 глянуть сайт и либо не пропускать совсем, либо пропустить, но не изменять пакет пришедший от клиента. Вроде бы splice, по документации из поставки самого squid, должен пропускать клиентский пакет к серверу без модификации. Или я чего-то не правильно понял? Вставить ник Quote Ответить с цитированием Share this post Link to post Share on other sites More sharing options...
