On 5/13/2014 12:29 PM, Yehuda Sadeh wrote: > On Tue, May 13, 2014 at 8:52 AM, Brian Rak <brak at gameservers.com> wrote: >> I hit a "bug" where radosgw crashed with >> >> -101> 2014-05-13 15:26:07.188494 7fde82886820 0 ERROR: FCGX_Accept_r >> returned -24 > too many files opened. You probably need to adjust your limits. > > >> .... >> 0> 2014-05-13 15:26:07.193772 7fde82886820 -1 rgw/rgw_main.cc: In function >> 'virtual void RGWProcess::RGWWQ::_clear()' thread 7fde82886820 time >> 2014-05-13 15:26:07.192212 >> rgw/rgw_main.cc: 181: FAILED assert(process->m_req_queue.empty()) >> >> ceph version 0.72.2 (a913ded2ff138aefb8cb84d347d72164099cfd60) >> 1: (ThreadPool::WorkQueue<RGWRequest>::_process(RGWRequest*)+0) [0x4ae9a0] >> 2: (ThreadPool::stop(bool)+0x1f5) [0x7fde8193ee05] >> 3: (RGWProcess::run()+0x358) [0x4ab808] >> 4: (main()+0x866) [0x4ac796] >> 5: (__libc_start_main()+0xfd) [0x7fde7fe02d1d] >> 6: radosgw() [0x45d239] >> >> >> It seems it ran out of fds, so I increased the limit and restarted it. >> However, now the user I was using can no longer access anything. Every >> action the user attempts is rejected with a 403 error. >> >> How do I enable logging of authentication issues? I don't see anything >> obvious in the config reference, and running radosgw with --debug doesn't >> produce output that makes sense. > > I usualy set "debug rgw = 20", and "debug ms = 1". Ah, that helped. It seems that s3cmd and ceph are calculating different signatures for some reason. Aside from a mismatch between public/secret keys, is there something else that could be causing this? 2014-05-13 16:39:30.895180 7fb0db5fe700 20 enqueued request req=0x7fb0f0012ce0 2014-05-13 16:39:30.895201 7fb0db5fe700 20 RGWWQ: 2014-05-13 16:39:30.895202 7fb0db5fe700 20 req: 0x7fb0f0012ce0 2014-05-13 16:39:30.895206 7fb0db5fe700 10 allocated request req=0x7fb0f00148d0 2014-05-13 16:39:30.895281 7fb0cb1e4700 20 dequeued request req=0x7fb0f0012ce0 2014-05-13 16:39:30.895286 7fb0cb1e4700 20 RGWWQ: empty 2014-05-13 16:39:30.895310 7fb0cb1e4700 20 CONTENT_LENGTH=0 2014-05-13 16:39:30.895311 7fb0cb1e4700 20 CONTENT_TYPE= 2014-05-13 16:39:30.895313 7fb0cb1e4700 20 FCGI_ROLE=RESPONDER 2014-05-13 16:39:30.895314 7fb0cb1e4700 20 HTTP_ACCEPT_ENCODING=identity 2014-05-13 16:39:30.895315 7fb0cb1e4700 20 HTTP_AUTHORIZATION=AWS MYACCESSKEY:FmglMmhJONIhpRHw7z9DgtvdnDI= 2014-05-13 16:39:30.895316 7fb0cb1e4700 20 HTTP_CONTENT_LENGTH=0 2014-05-13 16:39:30.895317 7fb0cb1e4700 20 HTTP_HOST=MYHOST 2014-05-13 16:39:30.895318 7fb0cb1e4700 20 HTTP_X_AMZ_DATE=Tue, 13 May 2014 16:39:30 +0000 2014-05-13 16:39:30.895319 7fb0cb1e4700 20 QUERY_STRING= 2014-05-13 16:39:30.895320 7fb0cb1e4700 20 REQUEST_METHOD=GET 2014-05-13 16:39:30.895322 7fb0cb1e4700 1 ====== starting new request req=0x7fb0f0012ce0 ===== 2014-05-13 16:39:30.895335 7fb0cb1e4700 2 req 5:0.000013::GET ::initializing 2014-05-13 16:39:30.895340 7fb0cb1e4700 10 host=MYHOST rgw_dns_name=MYHOST 2014-05-13 16:39:30.895353 7fb0cb1e4700 10 meta>> HTTP_X_AMZ_DATE 2014-05-13 16:39:30.895358 7fb0cb1e4700 10 x>> x-amz-date:Tue, 13 May 2014 16:39:30 +0000 2014-05-13 16:39:30.895374 7fb0cb1e4700 10 s->object=<NULL> s->bucket=<NULL> 2014-05-13 16:39:30.895380 7fb0cb1e4700 2 req 5:0.000059:s3:GET ::getting op 2014-05-13 16:39:30.895384 7fb0cb1e4700 2 req 5:0.000062:s3:GET :list_buckets:authorizing 2014-05-13 16:39:30.895423 7fb0cb1e4700 20 get_obj_state: rctx=0x7fb0f00141f0 obj=.users:MYACCESSKEY state=0x7fb0f0017d48 s->prefetch_data=0 2014-05-13 16:39:30.895432 7fb0cb1e4700 10 cache get: name=.users+MYACCESSKEY : hit 2014-05-13 16:39:30.895439 7fb0cb1e4700 20 get_obj_state: s->obj_tag was set empty 2014-05-13 16:39:30.895445 7fb0cb1e4700 10 cache get: name=.users+MYACCESSKEY : hit 2014-05-13 16:39:30.895478 7fb0cb1e4700 20 get_obj_state: rctx=0x7fb0f00141f0 obj=.users.uid:centosmirror state=0x7fb0f00186f8 s->prefetch_data=0 2014-05-13 16:39:30.895483 7fb0cb1e4700 10 cache get: name=.users.uid+centosmirror : hit 2014-05-13 16:39:30.895486 7fb0cb1e4700 20 get_obj_state: s->obj_tag was set empty 2014-05-13 16:39:30.895490 7fb0cb1e4700 10 cache get: name=.users.uid+centosmirror : hit 2014-05-13 16:39:30.895579 7fb0cb1e4700 10 get_canon_resource(): dest= 2014-05-13 16:39:30.895583 7fb0cb1e4700 10 auth_hdr: GET x-amz-date:Tue, 13 May 2014 16:39:30 +0000 2014-05-13 16:39:30.895650 7fb0cb1e4700 15 calculated digest=ck/6o9TgR73JLPT43SxIt39KgBI= 2014-05-13 16:39:30.895653 7fb0cb1e4700 15 auth_sign=FmglMmhJONIhpRHw7z9DgtvdnDI= 2014-05-13 16:39:30.895654 7fb0cb1e4700 15 compare=-1 2014-05-13 16:39:30.895657 7fb0cb1e4700 10 failed to authorize request 2014-05-13 16:39:30.895681 7fb0cb1e4700 5 nothing to log for operation 2014-05-13 16:39:30.895684 7fb0cb1e4700 2 req 5:0.000362:s3:GET :list_buckets:http status=403 2014-05-13 16:39:30.895688 7fb0cb1e4700 1 ====== req done req=0x7fb0f0012ce0 http_status=403 ======