Ticket #476: safariDebug_WORKSOK.txt

File safariDebug_WORKSOK.txt, 10.1 KB (added by devrandom.pip.verisignlabs.com, 12 years ago)

Debug from Safari session (i.e. works ok)

Line 
12013/12/28 19:00:27 [debug] 3727#0: epoll: fd:6 ev:0001 d:00007FA5F4C5C010
22013/12/28 19:00:27 [debug] 3727#0: accept on 0.0.0.0:443, ready: 0
32013/12/28 19:00:27 [debug] 3727#0: posix_memalign: 00000000018FEC70:256 @16
42013/12/28 19:00:27 [debug] 3727#0: *41 accept: 192.168.29.1 fd:3
52013/12/28 19:00:27 [debug] 3727#0: *41 event timer add: 3: 60000:1388257287001
62013/12/28 19:00:27 [debug] 3727#0: *41 reusable connection: 1
72013/12/28 19:00:27 [debug] 3727#0: *41 epoll add event: fd:3 op:1 ev:80000001
82013/12/28 19:00:27 [debug] 3727#0: timer delta: 141425
92013/12/28 19:00:27 [debug] 3727#0: posted events 0000000000000000
102013/12/28 19:00:27 [debug] 3727#0: worker cycle
112013/12/28 19:00:27 [debug] 3727#0: epoll timer: 60000
122013/12/28 19:00:27 [debug] 3727#0: epoll: fd:3 ev:0001 d:00007FA5F4C5C190
132013/12/28 19:00:27 [debug] 3727#0: *41 http check ssl handshake
142013/12/28 19:00:27 [debug] 3727#0: *41 http recv(): 1
152013/12/28 19:00:27 [debug] 3727#0: *41 https ssl handshake: 0x16
162013/12/28 19:00:27 [debug] 3727#0: *41 posix_memalign: 00000000018FBDD0:256 @16
172013/12/28 19:00:27 [debug] 3727#0: *41 SSL server name: "192.168.29.128"
182013/12/28 19:00:27 [debug] 3727#0: *41 SSL_do_handshake: -1
192013/12/28 19:00:27 [debug] 3727#0: *41 SSL_get_error: 2
202013/12/28 19:00:27 [debug] 3727#0: *41 reusable connection: 0
212013/12/28 19:00:27 [debug] 3727#0: timer delta: 1
222013/12/28 19:00:27 [debug] 3727#0: posted events 0000000000000000
232013/12/28 19:00:27 [debug] 3727#0: worker cycle
242013/12/28 19:00:27 [debug] 3727#0: epoll timer: 59999
252013/12/28 19:00:28 [debug] 3727#0: epoll: fd:3 ev:0001 d:00007FA5F4C5C190
262013/12/28 19:00:28 [debug] 3727#0: *41 SSL handshake handler: 0
272013/12/28 19:00:28 [debug] 3727#0: *41 verify:1, error:0, depth:1, subject:"/C=GB/ST=England/L=London/O=ITS/OU=test/CN=root.invalid",issuer: "/C=GB/ST=England/L=London/O=ITS/OU=test/CN=root.invalid"
282013/12/28 19:00:28 [debug] 3727#0: *41 verify:1, error:0, depth:0, subject:"/C=GB/ST=England/L=London/O=ITS/OU=test/CN=Demo Client",issuer: "/C=GB/ST=England/L=London/O=ITS/OU=test/CN=root.invalid"
292013/12/28 19:00:28 [debug] 3727#0: *41 SSL_do_handshake: 1
302013/12/28 19:00:28 [debug] 3727#0: *41 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES128-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AES(128) Mac=SHA256"
312013/12/28 19:00:28 [debug] 3727#0: *41 reusable connection: 1
322013/12/28 19:00:28 [debug] 3727#0: *41 http wait request handler
332013/12/28 19:00:28 [debug] 3727#0: *41 malloc: 0000000001949980:1024
342013/12/28 19:00:28 [debug] 3727#0: *41 SSL_read: -1
352013/12/28 19:00:28 [debug] 3727#0: *41 SSL_get_error: 2
362013/12/28 19:00:28 [debug] 3727#0: *41 free: 0000000001949980
372013/12/28 19:00:28 [debug] 3727#0: timer delta: 1452
382013/12/28 19:00:28 [debug] 3727#0: posted events 0000000000000000
392013/12/28 19:00:28 [debug] 3727#0: worker cycle
402013/12/28 19:00:28 [debug] 3727#0: epoll timer: 58547
412013/12/28 19:00:28 [debug] 3727#0: epoll: fd:3 ev:0001 d:00007FA5F4C5C190
422013/12/28 19:00:28 [debug] 3727#0: *41 http wait request handler
432013/12/28 19:00:28 [debug] 3727#0: *41 malloc: 0000000001949980:1024
442013/12/28 19:00:28 [debug] 3727#0: *41 SSL_read: 377
452013/12/28 19:00:28 [debug] 3727#0: *41 SSL_read: -1
462013/12/28 19:00:28 [debug] 3727#0: *41 SSL_get_error: 2
472013/12/28 19:00:28 [debug] 3727#0: *41 reusable connection: 0
482013/12/28 19:00:28 [debug] 3727#0: *41 posix_memalign: 00000000018E4A10:4096 @16
492013/12/28 19:00:28 [debug] 3727#0: *41 http process request line
502013/12/28 19:00:28 [debug] 3727#0: *41 http request line: "GET / HTTP/1.1"
512013/12/28 19:00:28 [debug] 3727#0: *41 http uri: "/"
522013/12/28 19:00:28 [debug] 3727#0: *41 http args: ""
532013/12/28 19:00:28 [debug] 3727#0: *41 http exten: ""
542013/12/28 19:00:28 [debug] 3727#0: *41 posix_memalign: 000000000194D8B0:4096 @16
552013/12/28 19:00:28 [debug] 3727#0: *41 http process request header line
562013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Host: 192.168.29.128"
572013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Pragma: no-cache"
582013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Accept-Encoding: gzip, deflate"
592013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Connection: keep-alive"
602013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
612013/12/28 19:00:28 [debug] 3727#0: *41 http header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_1) AppleWebKit/537.73.11 (KHTML, like Gecko) Version/7.0.1 Safari/537.73.11"
622013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Accept-Language: en-us"
632013/12/28 19:00:28 [debug] 3727#0: *41 http header: "DNT: 1"
642013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Cache-Control: no-cache"
652013/12/28 19:00:28 [debug] 3727#0: *41 http header done
662013/12/28 19:00:28 [debug] 3727#0: *41 event timer del: 3: 1388257287001
672013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 0
682013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 1
692013/12/28 19:00:28 [debug] 3727#0: *41 test location: "/"
702013/12/28 19:00:28 [debug] 3727#0: *41 test location: ~ "^(.+\.php)(.*)$"
712013/12/28 19:00:28 [debug] 3727#0: *41 using configuration "/"
722013/12/28 19:00:28 [debug] 3727#0: *41 http cl:-1 max:1048576
732013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 3
742013/12/28 19:00:28 [debug] 3727#0: *41 post rewrite phase: 4
752013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 5
762013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 6
772013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 7
782013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 8
792013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 9
802013/12/28 19:00:28 [debug] 3727#0: *41 post access phase: 10
812013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 11
822013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 12
832013/12/28 19:00:28 [debug] 3727#0: *41 open index "/usr/share/nginx/html/index.html"
842013/12/28 19:00:28 [debug] 3727#0: *41 internal redirect: "/index.html?"
852013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 1
862013/12/28 19:00:28 [debug] 3727#0: *41 test location: "/"
872013/12/28 19:00:28 [debug] 3727#0: *41 test location: ~ "^(.+\.php)(.*)$"
882013/12/28 19:00:28 [debug] 3727#0: *41 using configuration "/"
892013/12/28 19:00:28 [debug] 3727#0: *41 http cl:-1 max:1048576
902013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 3
912013/12/28 19:00:28 [debug] 3727#0: *41 post rewrite phase: 4
922013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 5
932013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 6
942013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 7
952013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 8
962013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 9
972013/12/28 19:00:28 [debug] 3727#0: *41 post access phase: 10
982013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 11
992013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 12
1002013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 13
1012013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 14
1022013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 15
1032013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 16
1042013/12/28 19:00:28 [debug] 3727#0: *41 http filename: "/usr/share/nginx/html/index.html"
1052013/12/28 19:00:28 [debug] 3727#0: *41 add cleanup: 00000000018E5778
1062013/12/28 19:00:28 [debug] 3727#0: *41 http static fd: 10
1072013/12/28 19:00:28 [debug] 3727#0: *41 http set discard body
1082013/12/28 19:00:28 [debug] 3727#0: *41 HTTP/1.1 200 OK
109Date: Sat, 28 Dec 2013 19:00:28 GMT
1102013/12/28 19:00:28 [debug] 3727#0: *41 write new buf t:1 f:0 000000000194DC90, pos 000000000194DC90, size: 237 file: 0, size: 0
1112013/12/28 19:00:28 [debug] 3727#0: *41 http write filter: l:0 f:0 s:237
1122013/12/28 19:00:28 [debug] 3727#0: *41 http output filter "/index.html?"
1132013/12/28 19:00:28 [debug] 3727#0: *41 http copy filter: "/index.html?"
1142013/12/28 19:00:28 [debug] 3727#0: *41 read: 10, 000000000194DDE0, 612, 0
1152013/12/28 19:00:28 [debug] 3727#0: *41 http postpone filter "/index.html?" 00000000018E59D8
1162013/12/28 19:00:28 [debug] 3727#0: *41 write old buf t:1 f:0 000000000194DC90, pos 000000000194DC90, size: 237 file: 0, size: 0
1172013/12/28 19:00:28 [debug] 3727#0: *41 write new buf t:1 f:1 000000000194DDE0, pos 000000000194DDE0, size: 612 file: 0, size: 612
1182013/12/28 19:00:28 [debug] 3727#0: *41 http write filter: l:1 f:0 s:849
1192013/12/28 19:00:28 [debug] 3727#0: *41 http write filter limit 0
1202013/12/28 19:00:28 [debug] 3727#0: *41 posix_memalign: 000000000194BB50:256 @16
1212013/12/28 19:00:28 [debug] 3727#0: *41 malloc: 000000000193C2D0:16384
1222013/12/28 19:00:28 [debug] 3727#0: *41 SSL buf copy: 237
1232013/12/28 19:00:28 [debug] 3727#0: *41 SSL buf copy: 612
1242013/12/28 19:00:28 [debug] 3727#0: *41 SSL to write: 849
1252013/12/28 19:00:28 [debug] 3727#0: *41 SSL_write: 849
1262013/12/28 19:00:28 [debug] 3727#0: *41 http write filter 0000000000000000
1272013/12/28 19:00:28 [debug] 3727#0: *41 http copy filter: 0 "/index.html?"
1282013/12/28 19:00:28 [debug] 3727#0: *41 http finalize request: 0, "/index.html?" a:1, c:2
1292013/12/28 19:00:28 [debug] 3727#0: *41 http request count:2 blk:0
1302013/12/28 19:00:28 [debug] 3727#0: *41 http finalize request: -4, "/index.html?" a:1, c:1
1312013/12/28 19:00:28 [debug] 3727#0: *41 set http keepalive handler
1322013/12/28 19:00:28 [debug] 3727#0: *41 http close request
1332013/12/28 19:00:28 [debug] 3727#0: *41 http log handler
1342013/12/28 19:00:28 [debug] 3727#0: *41 run cleanup: 00000000018E5778
1352013/12/28 19:00:28 [debug] 3727#0: *41 file cleanup: fd:10
1362013/12/28 19:00:28 [debug] 3727#0: *41 free: 00000000018E4A10, unused: 24
1372013/12/28 19:00:28 [debug] 3727#0: *41 free: 000000000194D8B0, unused: 1921
1382013/12/28 19:00:28 [debug] 3727#0: *41 free: 0000000001949980
1392013/12/28 19:00:28 [debug] 3727#0: *41 hc free: 0000000000000000 0
1402013/12/28 19:00:28 [debug] 3727#0: *41 hc busy: 0000000000000000 0
1412013/12/28 19:00:28 [debug] 3727#0: *41 free: 000000000193C2D0
1422013/12/28 19:00:28 [debug] 3727#0: *41 tcp_nodelay
1432013/12/28 19:00:28 [debug] 3727#0: *41 reusable connection: 1
1442013/12/28 19:00:28 [debug] 3727#0: *41 event timer add: 3: 65000:1388257293456
1452013/12/28 19:00:28 [debug] 3727#0: timer delta: 2
1462013/12/28 19:00:28 [debug] 3727#0: posted events 0000000000000000
1472013/12/28 19:00:28 [debug] 3727#0: worker cycle
1482013/12/28 19:00:28 [debug] 3727#0: epoll timer: 65000