SSL_write() failed (SSL:) (1: operation not permitted) when serving MP4 over HTTPS
insilica
nginx-forum at nginx.us
Tue Aug 12 09:28:36 UTC 2014
Hi,
I've searched the mailing list but haven't found anything relating to this
error:, the closest I found: http://trac.nginx.org/nginx/ticket/428 -
however that was closed 6 weeks ago and the error I get is with/without
SPDY.
I can't see whether I have misconfigured something? or it may be a bug.
SPDY error
nginx-error.log
[crit]: *12 SSL_write() failed (SSL:) (1: Operation not permitted) while
processing SPDY, client: 10.0.0.2, server: 0.0.0.0:443)
SSL error (no SPDY)
SSL_write() failed (SSL:) (1: Operation not permitted) while sending mp4 to
client, client: 10.0.0.2, server: dev.test.com, request: "GET
/video/homepage.mp4?start=0 HTTP/1.1", host: "dev.test.com", referrer:
"https://dev.test.com/index_test2.php"
Essentially the error arises when serving an MP4 with or without SPDY over
SSL. N.B. *Not* an issue over pure HTTP. Essentially the video appears,
plays in a loop when served over HTTP.
Over HTTPS the video playback starts OK but then stops abruptly with an
error.
The Setup
Client <---> Varnish <---> NGINX
*(I have tried disabling Varninsh, no difference)
nginx-debug.log
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 317-325
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 325-345
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 345-381
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 381-389
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 389-576
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 576-592
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 592-624
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 624-640
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 640-652
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 652-668
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 668-5180
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 5180-5196
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 5196-5220
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 5220-5240
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 5240-8076
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 8076-8092
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 8092-8660
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 8660-8668
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body skip
2014/08/12 09:15:10 [debug] 1370#0: *2 http range body buf: 8668-2208998
2014/08/12 09:15:10 [debug] 1370#0: *2 http copy filter:
"/video/homepage.mp4?start=0"
2014/08/12 09:15:10 [debug] 1370#0: *2 malloc: 0000000802239000:32768
2014/08/12 09:15:10 [debug] 1370#0: *2 read: 10, 0000000802239000, 32768,
168
2014/08/12 09:15:10 [debug] 1370#0: *2 http postpone filter
"/video/homepage.mp4?start=0" 00000008021AAA00
2014/08/12 09:15:10 [debug] 1370#0: *2 write new buf t:1 f:1
0000000802239000, pos 0000000802239000, size: 32768 file: 168, size: 32768
2014/08/12 09:15:10 [debug] 1370#0: *2 http write filter: l:0 f:1 s:32768
2014/08/12 09:15:10 [debug] 1370#0: *2 http write filter limit 0
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy:61 create DATA frame
00000008021AFF48: len:8192 flags:0
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy:61 create DATA frame
00000008021AAB48: len:8192 flags:0
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy:61 create DATA frame
00000008021AAC50: len:8192 flags:0
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy:61 create DATA frame
00000008021AAD58: len:8192 flags:0
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy frame out: 00000008021AAD58
sid:61 prio:2 bl:0 len:8192
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy frame out: 00000008021AAC50
sid:61 prio:2 bl:0 len:8192
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy frame out: 00000008021AAB48
sid:61 prio:2 bl:0 len:8192
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy frame out: 00000008021AFF48
sid:61 prio:2 bl:0 len:8192
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL buf copy: 8
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL buf copy: 8192
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL buf copy: 8
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL buf copy: 7796
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL to write: 16384
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL_write: -1
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL_get_error: 5
2014/08/12 09:15:10 [crit] 1370#0: *2 SSL_write() failed (SSL:) (1:
Operation not permitted) while processing SPDY, client: 10.0.0.2, server:
0.0.0.0:443
2014/08/12 09:15:10 [debug] 1370#0: *2 http write filter FFFFFFFFFFFFFFFF
2014/08/12 09:15:10 [debug] 1370#0: *2 http copy filter: -1
"/video/homepage.mp4?start=0"
2014/08/12 09:15:10 [debug] 1370#0: *2 http finalize request: -1,
"/video/homepage.mp4?start=0" a:1, c:1
2014/08/12 09:15:10 [debug] 1370#0: *2 http terminate request count:1
2014/08/12 09:15:10 [debug] 1370#0: *2 http terminate cleanup count:1 blk:0
2014/08/12 09:15:10 [debug] 1370#0: *2 http posted request:
"/video/homepage.mp4?start=0"
2014/08/12 09:15:10 [debug] 1370#0: *2 http terminate handler count:1
2014/08/12 09:15:10 [debug] 1370#0: *2 http request count:1 blk:0
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy close stream 61, queued 3,
processing 1
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy frame complete
pos:00000008021E8095 end:00000008021E80A1
2014/08/12 09:15:10 [debug] 1370#0: *2 process spdy frame head:80030006 f:0
l:4
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy PING frame
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy frame complete
pos:00000008021E80A1 end:00000008021E80A1
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy close stream handler
2014/08/12 09:15:10 [debug] 1370#0: *2 spdy close stream 61, queued 0,
processing 1
2014/08/12 09:15:10 [debug] 1370#0: *2 http close request
2014/08/12 09:15:10 [debug] 1370#0: *2 http log handler
2014/08/12 09:15:10 [debug] 1370#0: *2 run cleanup: 00000008021AFDA0
2014/08/12 09:15:10 [debug] 1370#0: *2 file cleanup: fd:10
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802239000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000803006000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008021AB000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008021AF000, unused: 0
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008021AA000, unused: 227
2014/08/12 09:15:10 [debug] 1370#0: *2 close http connection: 3
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL_shutdown: 1
2014/08/12 09:15:10 [debug] 1370#0: *2 event timer del: 3: 1407835071420
2014/08/12 09:15:10 [debug] 1370#0: *2 reusable connection: 0
2014/08/12 09:15:10 [debug] 1370#0: *2 run cleanup: 0000000802101530
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008021AE000, unused: 3040
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008021A6000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802231000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008021AD000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802132000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802106000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802081000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802104000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 000000080208B000
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 00000008020E3380
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802101000, unused: 0
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802101200, unused: 0
2014/08/12 09:15:10 [debug] 1370#0: *2 free: 0000000802101500, unused: 32
2014/08/12 09:15:10 [debug] 1370#0: timer delta: 17793
2014/08/12 09:15:10 [debug] 1370#0: posted events 0000000000000000
2014/08/12 09:15:10 [debug] 1370#0: worker cycle
2014/08/12 09:15:10 [debug] 1370#0: kevent timer: -1, changes: 0
==
Here is the server:
ssl_certificate /usr/local/etc/nginx/ssl/test.com.crt;
ssl_certificate_key /usr/local/etc/nginx/ssl/test.com.key;
# Resumption
ssl_session_cache shared:SSL:10m;
# Timeout
ssl_session_timeout 10m;
ssl_protocols SSLv3 TLSv1 TLSv1.1 TLSv1.2;
ssl_ciphers
'ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-
GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:DES-CBC3-SHA:HIGH:!aNULL:!eNULL:!EXPORT:!CAMELLIA:!DES:!MD5:!PSK:!RC4';
ssl_prefer_server_ciphers on;
server {
listen 443 ssl spdy;
server_name dev.test.com;
ssl on;
add_header Strict-Transport-Security "max-age=31536000;
includeSubDomains";
root /usr/local/www/dev.test.com;
index index.html index.htm;
#gzip off;
#charset koi8-r;
fastcgi_param HTTPS on;
location / {
try_files $uri $uri/ /index.php?$args;
location ~ \.php$ { include php-fpm; }
}
location ~ .mp4$ {
mp4;
mp4_buffer_size 4M;
mp4_max_buffer_size 10M;
}
location ~ .flv$ {
flv;
}
location ~* (file_a|file_b|file_c)\.php$ {
include php-fpm;
}
location /uploaddir {
location ~ \.php$ {return 403;}
}
#access_log logs/host.access.log main;
#Deny access to '.' files and directories
location ~ /\. {
access_log off;
log_not_found off;
deny all;
}
}
Looking at the debug logs:
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL_write: -1
2014/08/12 09:15:10 [debug] 1370#0: *2 SSL_get_error: 5
Could this be an nginx <-> openssl interface error?
Any help or pointers would be much appreciated.
Thanks
Posted at Nginx Forum: http://forum.nginx.org/read.php?2,252494,252494#msg-252494
More information about the nginx
mailing list