snik_1900 Posted June 26, 2017 · Report post Доброго дня. Может кто сталкивался с такой проблемой. Уже месяц бьюсь, решить не могу. Есть 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 Share this post Link to post Share on other sites
alibek Posted June 27, 2017 · Report post Запросы на сквид вообще не приходят? Или приходят, но не обслуживаются? Коневой самоподписанный CA установлен у клиентов? А вообще я бы советовал не тратить время, через сквид блокировку сайтов не обеспечить. Share this post Link to post Share on other sites
snik_1900 Posted June 27, 2017 · Report post Запросы на сквид вообще не приходят? В логах ничего не отображается. Или приходят, но не обслуживаются? Скорее всего. Коневой самоподписанный CA установлен у клиентов? SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. А вообще я бы советовал не тратить время, через сквид блокировку сайтов не обеспечить. Уже 2 года работает. Проблема только с https. Раньше не обращали внимания, а после проблем с DNSами озадачились. Share this post Link to post Share on other sites
alibek Posted June 27, 2017 · Report post В логах ничего не отображается. Так надо tcpdump смотреть. SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. Какая-то загадочная фраза. Насколько я знаю, через сквид пропускать https-трафик только с помощью MITM, установив у клиентов свой корневой CA и подписывая им поддельные сертификаты. Может конечно путаю с чем-то, но каким образом сквид извлечет из зашифрованного трафика строку запроса? Share this post Link to post Share on other sites
snik_1900 Posted June 27, 2017 · Report post 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 имя домена. Share this post Link to post Share on other sites
alibek Posted June 27, 2017 · Report post Любопытно, пожалуй действительно должно работать (на уровне доменов, конечно, а не URL). Но на https нельзя сделать редирект или показать заглушку, можно только разорвать соединение. Скорее всего в этом этапе что-то не срабатывает. Share this post Link to post Share on other sites
alibek Posted June 27, 2017 · Report post Кстати, в конфиге я не вижу ssl_bump terminate ssl_sites Share this post Link to post Share on other sites
snik_1900 Posted June 27, 2017 (edited) · Report post Кстати, в конфиге я не вижу ssl_bump terminate ssl_sites А зачем? Есть: ssl_bump bump ssl_sites и ssl_bump peek step1. Edited June 27, 2017 by snik_1900 Share this post Link to post Share on other sites
snik_1900 Posted July 6, 2017 · Report post Свежих мыслей нет? Или SQUID редкий зверь? Share this post Link to post Share on other sites
Ivan_83 Posted July 6, 2017 · Report post SQUID в прозрачном режиме. Соответсвенно у клиентов сертификат не устанавливается. А сам по себе он существует. Сертификат у клиента должен стоять в любом случае, иначе он будет показывать ошибку, потому что не доверенное. Что тебе тцпдам показывает? Share this post Link to post Share on other sites
snik_1900 Posted July 6, 2017 · Report post 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. Или я чего-то недопонимаю? Share this post Link to post Share on other sites
Ivan_83 Posted July 6, 2017 · Report post Я вот не уверен что fwd делает dst nat. У меня на PF rdr вроде делает Share this post Link to post Share on other sites
snik_1900 Posted July 7, 2017 · Report post Я вот не уверен что 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й? Share this post Link to post Share on other sites
snik_1900 Posted July 18, 2017 (edited) · Report post Удалось добиться: При попытке открыть 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 Share this post Link to post Share on other sites
snik_1900 Posted August 10, 2017 (edited) · Report post Может это поможет найти проблему. Более детальный лог: 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 Share this post Link to post Share on other sites
mixtery Posted August 11, 2017 · Report post Ташовыкажете? Попробуй подмени сертификат без установленного своего у клиента. Забудьте это. Хватит курить манулы двухлетней давности. Share this post Link to post Share on other sites
snik_1900 Posted August 14, 2017 · Report post Ташовыкажете? Попробуй подмени сертификат без установленного своего у клиента. Забудьте это. Хватит курить манулы двухлетней давности. А без подмены никак? На шаге step1 глянуть сайт и либо не пропускать совсем, либо пропустить, но не изменять пакет пришедший от клиента. Вроде бы splice, по документации из поставки самого squid, должен пропускать клиентский пакет к серверу без модификации. Или я чего-то не правильно понял? Share this post Link to post Share on other sites
