Re: [squid-users] Squid 3.3 Reverse Proxy Mode - 502 Errors when uploading files larger than 6MB

From: Madhav V Diwan <mdiwan_at_diwanconsulting.com>
Date: Fri, 22 Nov 2013 23:36:27 -0500

Eliezer

 I just now tried a connection with the cache_peer set to port 80
without SSL , i left the frontend ssl

same result.. tiny file makes it through , larger files do not.

Madhav

this is what seems to be wrong..

2013/11/22 23:21:02.291 kid1| http.cc(1080) persistentConnStatus:
local=192.168.17.68:49060 remote=192.168.17.24:80 FD 41 flags=1 eof=0
> 2013/11/22 23:21:02.291 kid1| http.cc(1055) statusIfComplete:
statusIfComplete: Request not yet fully sent "POST
https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1"
> 2013/11/22 23:21:02.292 kid1| forward.cc(426) unregister:
https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1
> 2013/11/22 23:21:02.292 kid1| comm.cc(1102) _comm_close: comm_close:
start closing FD 41
> 2013/11/22 23:21:02.292 kid1| comm.cc(760) commUnsetFdTimeout: Remove
timeout for FD 41

why close the FD immediately if the request is not yet complete??

debug ALL,3 below
 from cache.log .. all i got from access log was the 401 errors

> ----------
> 2013/11/22 23:21:02.291 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
> 2013/11/22 23:21:02.291 kid1| store_client.cc(757) invokeHandlers: InvokeHandlers: 73DFA61D9A9E373CCBB16FF0FB32CF16
> 2013/11/22 23:21:02.291 kid1| store_client.cc(763) invokeHandlers: StoreEntry::InvokeHandlers: checking client #0
> 2013/11/22 23:21:02.291 kid1| http.cc(1080) persistentConnStatus: local=192.168.17.68:49060 remote=192.168180.204.17.24:80 FD 41 flags=1 eof=0
> 2013/11/22 23:21:02.291 kid1| http.cc(1055) statusIfComplete: statusIfComplete: Request not yet fully sent "POST https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1"
> 2013/11/22 23:21:02.292 kid1| forward.cc(426) unregister: https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1
> 2013/11/22 23:21:02.292 kid1| comm.cc(1102) _comm_close: comm_close: start closing FD 41
> 2013/11/22 23:21:02.292 kid1| comm.cc(760) commUnsetFdTimeout: Remove timeout for FD 41
> 2013/11/22 23:21:02.292 kid1| forward.cc(451) complete: https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1
> status 401
> 2013/11/22 23:21:02.292 kid1| forward.cc(1212) reforward: https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1?
> 2013/11/22 23:21:02.292 kid1| forward.cc(1215) reforward: No, ENTRY_FWD_HDR_WAIT isn't set
> 2013/11/22 23:21:02.292 kid1| forward.cc(475) complete: server (FD closed) not re-forwarding status 401
> 2013/11/22 23:21:02.292 kid1| store.cc(1068) complete: storeComplete: '73DFA61D9A9E373CCBB16FF0FB32CF16'
> 2013/11/22 23:21:02.292 kid1| store.cc(1369) validLength: storeEntryValidLength: Checking '73DFA61D9A9E373CCBB16FF0FB32CF16'
> 2013/11/22 23:21:02.292 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
> 2013/11/22 23:21:02.292 kid1| store_client.cc(757) invokeHandlers: InvokeHandlers: 73DFA61D9A9E373CCBB16FF0FB32CF16
> 2013/11/22 23:21:02.292 kid1| store_client.cc(763) invokeHandlers: StoreEntry::InvokeHandlers: checking client #0
> 2013/11/22 23:21:02.292 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 1
> 2013/11/22 23:21:02.292 kid1| store.cc(570) unlock: StoreEntry::unlock: key '73DFA61D9A9E373CCBB16FF0FB32CF16' count=3
> 2013/11/22 23:21:02.292 kid1| forward.cc(248) ~FwdState: FwdState destructor starting
> 2013/11/22 23:21:02.292 kid1| store.cc(570) unlock: StoreEntry::unlock: key '73DFA61D9A9E373CCBB16FF0FB32CF16' count=2
> 2013/11/22 23:21:02.292 kid1| AsyncCall.cc(48) cancel: will not call fwdConnectDoneWrapper [call7302959] because FwdState destructed
> 2013/11/22 23:21:02.293 kid1| forward.cc(278) ~FwdState: FwdState destructor done
> 2013/11/22 23:21:02.293 kid1| fd.cc(116) fd_close: fd_close FD 41 https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F7
> 2013/11/22 23:21:02.293 kid1| IoCallback.cc(108) finish: called for local=172.16.20.68:443 remote=69.125.192.168:42441 FD 39 flags=1 (0, 0)
> 2013/11/22 23:21:02.293 kid1| client_side_reply.cc(1082) storeOKTransferDone: storeOKTransferDone out.offset=0 objectLen()=314 headers_sz=314
> 2013/11/22 23:21:02.293 kid1| client_side.cc(1543) keepaliveNextRequest: ConnnStateData(local=172.16.20.68:443 remote=69.125.192.168:42441 FD 39 flags=1), Context(local=172.16.20.68:443 remote=69.125.192.168:42441 FD 39 flags=1)
> 2013/11/22 23:21:02.293 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7fca4b9bbcb8
> 2013/11/22 23:21:02.293 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7fca4b9bbcb8
> 2013/11/22 23:21:02.293 kid1| client_side_request.cc(291) ~ClientHttpRequest: httpRequestFree: https://portal.mydomain.com/IT/_layouts/Upload.aspx?List={F74C75F7-1E25-4655-814C-41BA9F873167}&RootFolder=&IsDlg=1
> 2013/11/22 23:21:02.293 kid1| store.cc(570) unlock: StoreEntry::unlock: key '73DFA61D9A9E373CCBB16FF0FB32CF16' count=1
> 2013/11/22 23:21:02.293 kid1| clientStream.cc(270) clientStreamAbort: clientStreamAbort: Aborting stream with tail 0x7fca4b9d0898
> 2013/11/22 23:21:02.294 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7fca4b9d0898
> 2013/11/22 23:21:02.294 kid1| clientStream.cc(246) clientStreamDetach: clientStreamDetach: Calling 1 with cbdata 0x7fca4b9c0b20
> 2013/11/22 23:21:02.294 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7fca4b9d0898
> 2013/11/22 23:21:02.294 kid1| store_client.cc(693) storeUnregister: storeUnregister: called for '73DFA61D9A9E373CCBB16FF0FB32CF16'
> 2013/11/22 23:21:02.294 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
> 2013/11/22 23:21:02.294 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
> 2013/11/22 23:21:02.294 kid1| store.cc(570) unlock: StoreEntry::unlock: key '73DFA61D9A9E373CCBB16FF0FB32CF16' count=0
> 2013/11/22 23:21:02.294 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
> 2013/11/22 23:21:02.294 kid1| store.cc(1261) release: storeRelease: Releasing: '73DFA61D9A9E373CCBB16FF0FB32CF16'
> 2013/11/22 23:21:02.294 kid1| store.cc(466) destroyStoreEntry: destroyStoreEntry: destroying 0x7fca4ca0fdb8
> 2013/11/22 23:21:02.294 kid1| store.cc(444) destroyMemObject: destroyMemObject 0x7fca4ca0fe30
> 2013/11/22 23:21:02.294 kid1| MemObject.cc(111) ~MemObject: del MemObject 0x7fca4ca0fe30
> 2013/11/22 23:21:02.294 kid1| client_side.cc(1567) keepaliveNextRequest: closing for earlier request error: virgin request body consumer aborted
> 2013/11/22 23:21:02.294 kid1| comm.cc(1102) _comm_close: comm_close: start closing FD 39
> 2013/11/22 23:21:02.295 kid1| comm.cc(760) commUnsetFdTimeout: Remove timeout for FD 39
> 2013/11/22 23:21:02.295 kid1| IoCallback.cc(108) finish: called for local=172.16.20.68:443 remote=69.125.192.168:42441 FD 39 flags=1 (-10, 0)
> 2013/11/22 23:21:02.295 kid1| client_side.cc(777) swanSong: local=172.16.20.68:443 remote=69.125.192.168:42441 flags=1
> 2013/11/22 23:21:02.295 kid1| client_side.cc(4508) unpinConnection:
> 2013/11/22 23:21:02.295 kid1| client_side.cc(810) ~ConnStateData:
> 2013/11/22 23:21:02.295 kid1| fd.cc(116) fd_close: fd_close FD 39 Reading next request

-----Original Message-----T
o: squid-users_at_squid-cache.org

Date: Sat, 23 Nov 2013 03:08:53 +0200

Sorry for the typo:
It's 25M for both values.

Eliezer

On 23/11/13 01:51, Eliezer Croitoru wrote:
> Hey,
>
> I would try to test it per case to understand the issue.
> lets take a simple apache server using a POST form to upload a file:
> upload_max_filesize = 10M
> post_max_size = 10M
>
> Set the above in php.ini.
Received on Sat Nov 23 2013 - 04:36:34 MST

This archive was generated by hypermail 2.2.0 : Tue Nov 26 2013 - 12:00:04 MST