nginx ssl_write returns SSL_ERROR_WANT_WRITE and retry after many seconds

I'm using nginx-1.7.3 + openssl1.0.1j to do a https web proxy in front of my real server.

I found there are always some requests' $request_time is much bigger than $upstream_response_time.

I checked many cases, and the reason is SSL_write.

In the following log. at 19:43:08 SSL_write: -1 SSL_get_error: 3 and then at 19:43:12 the write event is triggered again. 4 seconds after SSL_ERROR_WANT_WRITE.

I wonder why it takes so long for openssl to be writeable again? How can I avoid this?

By the way, not all the requests take so long after SSL_ERROR_WANT_WRITE .This makes me very confused.

2016/04/28 19:43:08 [debug] 1220#0: *9791 finalize http proxy request
2016/04/28 19:43:08 [debug] 1220#0: *9791 free keepalive peer
2016/04/28 19:43:08 [debug] 1220#0: *9791 free keepalive peer: saving coection 00007F34563801C8
2016/04/28 19:43:08 [debug] 1220#0: *9791 event timer del: 16: 1461843798061
2016/04/28 19:43:08 [debug] 1220#0: *9791 free rr peer 1 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 http upstream temp fd: 14
2016/04/28 19:43:08 [debug] 1220#0: *9791 http output filter "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0"
2016/04/28 19:43:08 [debug] 1220#0: *9791 http copy filter: "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0"
2016/04/28 19:43:08 [debug] 1220#0: *9791 http postpone filter "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0" 0000000002904630 
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 0000000002887B40, pos 0000000002888B07, size: 57 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:1 0000000002906840, pos 0000000002906840, size: 32768 file: 0, size: 32768
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 0000000002888B50, pos 0000000002888B50, size: 4096 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 00000000029313A0, pos 00000000029313A0, size: 4096 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 000000000292F380, pos 000000000292F380, size: 4096 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 0000000002930390, pos 0000000002930390, size: 4096 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 00000000028BB770, pos 00000000028BB770, size: 4096 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 00000000028BC780, pos 00000000028BC780, size: 4096 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write old buf t:1 f:0 0000000002923830, pos 0000000002923830, size: 231 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 http write filter: l:1 f:1 s:57632
2016/04/28 19:43:08 [debug] 1220#0: *9791 http write filter limit 0
2016/04/28 19:43:08 [debug] 1220#0: *9791 SSL to write: 16384
2016/04/28 19:43:08 [debug] 1220#0: *9791 SSL_write: -1 
2016/04/28 19:43:08 [debug] 1220#0: *9791 SSL_get_error: 3
2016/04/28 19:43:08 [debug] 1220#0: *9791 http write filter 0000000002904408
2016/04/28 19:43:08 [debug] 1220#0: *9791 http copy filter: -2 "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0"
2016/04/28 19:43:08 [debug] 1220#0: *9791 http finalize request: -2, "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0" a:1, c:1
2016/04/28 19:43:08 [debug] 1220#0: *9791 event timer: 35, old:1461843793074, new: 1461843793074
2016/04/28 19:43:12 [debug] 1220#0: *9791 http run request: "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0"
2016/04/28 19:43:12 [debug] 1220#0: *9791 http writer handler: "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0"
2016/04/28 19:43:12 [debug] 1220#0: *9791 http output filter "/psb?/V117RuFG4UFDCe/KdcrJSyz9rGJE5o0yedyvh7mBhJCG.Ekp6jmFXiL78g!/b/dFcBAAAAAAAA&ek=1&kp=1&pt=0&bo=gAJVAwAAAAAFB*A!&sce=22-1-1&rf=4-0"