]>
Commit | Line | Data |
---|---|---|
7c673cae | 1 | // -*- mode:C++; tab-width:8; c-basic-offset:2; indent-tabs-mode:t -*- |
9f95a23c | 2 | // vim: ts=8 sw=2 smarttab ft=cpp |
7c673cae FG |
3 | |
4 | #include "common/Clock.h" | |
5 | #include "common/Timer.h" | |
6 | #include "common/utf8.h" | |
7 | #include "common/OutputDataSocket.h" | |
8 | #include "common/Formatter.h" | |
9 | ||
10 | #include "rgw_bucket.h" | |
11 | #include "rgw_log.h" | |
12 | #include "rgw_acl.h" | |
7c673cae FG |
13 | #include "rgw_client_io.h" |
14 | #include "rgw_rest.h" | |
11fdf7f2 | 15 | #include "rgw_zone.h" |
20effc67 | 16 | #include "rgw_rados.h" |
11fdf7f2 TL |
17 | |
18 | #include "services/svc_zone.h" | |
7c673cae | 19 | |
a4b75251 TL |
20 | #include <chrono> |
21 | #include <math.h> | |
22 | ||
7c673cae FG |
23 | #define dout_subsys ceph_subsys_rgw |
24 | ||
20effc67 TL |
25 | using namespace std; |
26 | ||
1e59de90 | 27 | static void set_param_str(req_state *s, const char *name, string& str) |
7c673cae FG |
28 | { |
29 | const char *p = s->info.env->get(name); | |
30 | if (p) | |
31 | str = p; | |
32 | } | |
33 | ||
34 | string render_log_object_name(const string& format, | |
f67539c2 | 35 | struct tm *dt, const string& bucket_id, |
7c673cae FG |
36 | const string& bucket_name) |
37 | { | |
38 | string o; | |
39 | for (unsigned i=0; i<format.size(); i++) { | |
40 | if (format[i] == '%' && i+1 < format.size()) { | |
41 | i++; | |
42 | char buf[32]; | |
43 | switch (format[i]) { | |
44 | case '%': | |
45 | strcpy(buf, "%"); | |
46 | break; | |
47 | case 'Y': | |
48 | sprintf(buf, "%.4d", dt->tm_year + 1900); | |
49 | break; | |
50 | case 'y': | |
51 | sprintf(buf, "%.2d", dt->tm_year % 100); | |
52 | break; | |
53 | case 'm': | |
54 | sprintf(buf, "%.2d", dt->tm_mon + 1); | |
55 | break; | |
56 | case 'd': | |
57 | sprintf(buf, "%.2d", dt->tm_mday); | |
58 | break; | |
59 | case 'H': | |
60 | sprintf(buf, "%.2d", dt->tm_hour); | |
61 | break; | |
62 | case 'I': | |
63 | sprintf(buf, "%.2d", (dt->tm_hour % 12) + 1); | |
64 | break; | |
65 | case 'k': | |
66 | sprintf(buf, "%d", dt->tm_hour); | |
67 | break; | |
68 | case 'l': | |
69 | sprintf(buf, "%d", (dt->tm_hour % 12) + 1); | |
70 | break; | |
71 | case 'M': | |
72 | sprintf(buf, "%.2d", dt->tm_min); | |
73 | break; | |
74 | ||
75 | case 'i': | |
76 | o += bucket_id; | |
77 | continue; | |
78 | case 'n': | |
79 | o += bucket_name; | |
80 | continue; | |
81 | default: | |
82 | // unknown code | |
83 | sprintf(buf, "%%%c", format[i]); | |
84 | break; | |
85 | } | |
86 | o += buf; | |
87 | continue; | |
88 | } | |
89 | o += format[i]; | |
90 | } | |
91 | return o; | |
92 | } | |
93 | ||
94 | /* usage logger */ | |
b3b6e05e | 95 | class UsageLogger : public DoutPrefixProvider { |
7c673cae | 96 | CephContext *cct; |
1e59de90 | 97 | rgw::sal::Driver* driver; |
7c673cae | 98 | map<rgw_user_bucket, RGWUsageBatch> usage_map; |
9f95a23c | 99 | ceph::mutex lock = ceph::make_mutex("UsageLogger"); |
7c673cae | 100 | int32_t num_entries; |
9f95a23c | 101 | ceph::mutex timer_lock = ceph::make_mutex("UsageLogger::timer_lock"); |
7c673cae FG |
102 | SafeTimer timer; |
103 | utime_t round_timestamp; | |
104 | ||
105 | class C_UsageLogTimeout : public Context { | |
106 | UsageLogger *logger; | |
107 | public: | |
108 | explicit C_UsageLogTimeout(UsageLogger *_l) : logger(_l) {} | |
109 | void finish(int r) override { | |
110 | logger->flush(); | |
111 | logger->set_timer(); | |
112 | } | |
113 | }; | |
114 | ||
115 | void set_timer() { | |
116 | timer.add_event_after(cct->_conf->rgw_usage_log_tick_interval, new C_UsageLogTimeout(this)); | |
117 | } | |
118 | public: | |
119 | ||
1e59de90 | 120 | UsageLogger(CephContext *_cct, rgw::sal::Driver* _driver) : cct(_cct), driver(_driver), num_entries(0), timer(cct, timer_lock) { |
7c673cae | 121 | timer.init(); |
9f95a23c | 122 | std::lock_guard l{timer_lock}; |
7c673cae FG |
123 | set_timer(); |
124 | utime_t ts = ceph_clock_now(); | |
125 | recalc_round_timestamp(ts); | |
126 | } | |
127 | ||
128 | ~UsageLogger() { | |
9f95a23c | 129 | std::lock_guard l{timer_lock}; |
7c673cae FG |
130 | flush(); |
131 | timer.cancel_all_events(); | |
132 | timer.shutdown(); | |
133 | } | |
134 | ||
135 | void recalc_round_timestamp(utime_t& ts) { | |
136 | round_timestamp = ts.round_to_hour(); | |
137 | } | |
138 | ||
139 | void insert_user(utime_t& timestamp, const rgw_user& user, rgw_usage_log_entry& entry) { | |
9f95a23c | 140 | lock.lock(); |
7c673cae FG |
141 | if (timestamp.sec() > round_timestamp + 3600) |
142 | recalc_round_timestamp(timestamp); | |
143 | entry.epoch = round_timestamp.sec(); | |
144 | bool account; | |
145 | string u = user.to_str(); | |
146 | rgw_user_bucket ub(u, entry.bucket); | |
147 | real_time rt = round_timestamp.to_real_time(); | |
148 | usage_map[ub].insert(rt, entry, &account); | |
149 | if (account) | |
150 | num_entries++; | |
151 | bool need_flush = (num_entries > cct->_conf->rgw_usage_log_flush_threshold); | |
9f95a23c | 152 | lock.unlock(); |
7c673cae | 153 | if (need_flush) { |
9f95a23c | 154 | std::lock_guard l{timer_lock}; |
7c673cae FG |
155 | flush(); |
156 | } | |
157 | } | |
158 | ||
159 | void insert(utime_t& timestamp, rgw_usage_log_entry& entry) { | |
160 | if (entry.payer.empty()) { | |
161 | insert_user(timestamp, entry.owner, entry); | |
162 | } else { | |
163 | insert_user(timestamp, entry.payer, entry); | |
164 | } | |
165 | } | |
166 | ||
167 | void flush() { | |
168 | map<rgw_user_bucket, RGWUsageBatch> old_map; | |
9f95a23c | 169 | lock.lock(); |
7c673cae FG |
170 | old_map.swap(usage_map); |
171 | num_entries = 0; | |
9f95a23c | 172 | lock.unlock(); |
7c673cae | 173 | |
f51cf556 | 174 | driver->log_usage(this, old_map, null_yield); |
7c673cae | 175 | } |
b3b6e05e TL |
176 | |
177 | CephContext *get_cct() const override { return cct; } | |
178 | unsigned get_subsys() const override { return dout_subsys; } | |
179 | std::ostream& gen_prefix(std::ostream& out) const override { return out << "rgw UsageLogger: "; } | |
7c673cae FG |
180 | }; |
181 | ||
182 | static UsageLogger *usage_logger = NULL; | |
183 | ||
1e59de90 | 184 | void rgw_log_usage_init(CephContext *cct, rgw::sal::Driver* driver) |
7c673cae | 185 | { |
1e59de90 | 186 | usage_logger = new UsageLogger(cct, driver); |
7c673cae FG |
187 | } |
188 | ||
189 | void rgw_log_usage_finalize() | |
190 | { | |
191 | delete usage_logger; | |
192 | usage_logger = NULL; | |
193 | } | |
194 | ||
1e59de90 | 195 | static void log_usage(req_state *s, const string& op_name) |
7c673cae FG |
196 | { |
197 | if (s->system_request) /* don't log system user operations */ | |
198 | return; | |
199 | ||
200 | if (!usage_logger) | |
201 | return; | |
202 | ||
f51cf556 TL |
203 | std::string user; |
204 | std::string payer; | |
7c673cae FG |
205 | string bucket_name; |
206 | ||
207 | bucket_name = s->bucket_name; | |
208 | ||
209 | if (!bucket_name.empty()) { | |
f51cf556 TL |
210 | bucket_name = s->bucket_name; |
211 | user = to_string(s->bucket_owner.id); | |
20effc67 | 212 | if (!rgw::sal::Bucket::empty(s->bucket.get()) && |
f67539c2 | 213 | s->bucket->get_info().requester_pays) { |
f51cf556 | 214 | payer = s->user->get_id().to_str(); |
7c673cae FG |
215 | } |
216 | } else { | |
f51cf556 | 217 | user = to_string(s->owner.id); |
7c673cae FG |
218 | } |
219 | ||
220 | bool error = s->err.is_err(); | |
221 | if (error && s->err.http_ret == 404) { | |
222 | bucket_name = "-"; /* bucket not found, use the invalid '-' as bucket name */ | |
223 | } | |
224 | ||
f51cf556 | 225 | rgw_usage_log_entry entry(user, payer, bucket_name); |
7c673cae FG |
226 | |
227 | uint64_t bytes_sent = ACCOUNTING_IO(s)->get_bytes_sent(); | |
228 | uint64_t bytes_received = ACCOUNTING_IO(s)->get_bytes_received(); | |
229 | ||
230 | rgw_usage_data data(bytes_sent, bytes_received); | |
231 | ||
232 | data.ops = 1; | |
31f18b77 | 233 | if (!s->is_err()) |
7c673cae FG |
234 | data.successful_ops = 1; |
235 | ||
b3b6e05e | 236 | ldpp_dout(s, 30) << "log_usage: bucket_name=" << bucket_name |
181888fb FG |
237 | << " tenant=" << s->bucket_tenant |
238 | << ", bytes_sent=" << bytes_sent << ", bytes_received=" | |
239 | << bytes_received << ", success=" << data.successful_ops << dendl; | |
240 | ||
7c673cae FG |
241 | entry.add(op_name, data); |
242 | ||
243 | utime_t ts = ceph_clock_now(); | |
244 | ||
245 | usage_logger->insert(ts, entry); | |
246 | } | |
247 | ||
248 | void rgw_format_ops_log_entry(struct rgw_log_entry& entry, Formatter *formatter) | |
249 | { | |
250 | formatter->open_object_section("log_entry"); | |
251 | formatter->dump_string("bucket", entry.bucket); | |
f51cf556 | 252 | formatter->dump_string("object", entry.obj.name); |
11fdf7f2 TL |
253 | { |
254 | auto t = utime_t{entry.time}; | |
255 | t.gmtime(formatter->dump_stream("time")); // UTC | |
256 | t.localtime(formatter->dump_stream("time_local")); | |
257 | } | |
7c673cae | 258 | formatter->dump_string("remote_addr", entry.remote_addr); |
f51cf556 | 259 | string obj_owner = to_string(entry.object_owner); |
7c673cae FG |
260 | if (obj_owner.length()) |
261 | formatter->dump_string("object_owner", obj_owner); | |
262 | formatter->dump_string("user", entry.user); | |
263 | formatter->dump_string("operation", entry.op); | |
264 | formatter->dump_string("uri", entry.uri); | |
265 | formatter->dump_string("http_status", entry.http_status); | |
266 | formatter->dump_string("error_code", entry.error_code); | |
267 | formatter->dump_int("bytes_sent", entry.bytes_sent); | |
268 | formatter->dump_int("bytes_received", entry.bytes_received); | |
269 | formatter->dump_int("object_size", entry.obj_size); | |
11fdf7f2 TL |
270 | { |
271 | using namespace std::chrono; | |
272 | uint64_t total_time = duration_cast<milliseconds>(entry.total_time).count(); | |
273 | formatter->dump_int("total_time", total_time); | |
274 | } | |
7c673cae FG |
275 | formatter->dump_string("user_agent", entry.user_agent); |
276 | formatter->dump_string("referrer", entry.referrer); | |
277 | if (entry.x_headers.size() > 0) { | |
278 | formatter->open_array_section("http_x_headers"); | |
279 | for (const auto& iter: entry.x_headers) { | |
280 | formatter->open_object_section(iter.first.c_str()); | |
281 | formatter->dump_string(iter.first.c_str(), iter.second); | |
282 | formatter->close_section(); | |
283 | } | |
284 | formatter->close_section(); | |
285 | } | |
9f95a23c | 286 | formatter->dump_string("trans_id", entry.trans_id); |
20effc67 TL |
287 | switch(entry.identity_type) { |
288 | case TYPE_RGW: | |
289 | formatter->dump_string("authentication_type","Local"); | |
290 | break; | |
291 | case TYPE_LDAP: | |
292 | formatter->dump_string("authentication_type","LDAP"); | |
293 | break; | |
294 | case TYPE_KEYSTONE: | |
295 | formatter->dump_string("authentication_type","Keystone"); | |
296 | break; | |
297 | case TYPE_WEB: | |
298 | formatter->dump_string("authentication_type","OIDC Provider"); | |
299 | break; | |
300 | case TYPE_ROLE: | |
301 | formatter->dump_string("authentication_type","STS"); | |
302 | break; | |
f51cf556 TL |
303 | case TYPE_ROOT: |
304 | formatter->dump_string("authentication_type", "Local Account Root"); | |
305 | break; | |
20effc67 TL |
306 | default: |
307 | break; | |
308 | } | |
adb31ebb TL |
309 | if (entry.token_claims.size() > 0) { |
310 | if (entry.token_claims[0] == "sts") { | |
20effc67 | 311 | formatter->open_object_section("sts_info"); |
adb31ebb TL |
312 | for (const auto& iter: entry.token_claims) { |
313 | auto pos = iter.find(":"); | |
314 | if (pos != string::npos) { | |
315 | formatter->dump_string(iter.substr(0, pos), iter.substr(pos + 1)); | |
316 | } | |
317 | } | |
318 | formatter->close_section(); | |
319 | } | |
320 | } | |
2a845540 TL |
321 | if (!entry.access_key_id.empty()) { |
322 | formatter->dump_string("access_key_id", entry.access_key_id); | |
323 | } | |
324 | if (!entry.subuser.empty()) { | |
325 | formatter->dump_string("subuser", entry.subuser); | |
326 | } | |
327 | formatter->dump_bool("temp_url", entry.temp_url); | |
39ae355f TL |
328 | |
329 | if (entry.op == "multi_object_delete") { | |
330 | formatter->open_object_section("op_data"); | |
331 | formatter->dump_int("num_ok", entry.delete_multi_obj_meta.num_ok); | |
332 | formatter->dump_int("num_err", entry.delete_multi_obj_meta.num_err); | |
333 | formatter->open_array_section("objects"); | |
334 | for (const auto& iter: entry.delete_multi_obj_meta.objects) { | |
335 | formatter->open_object_section(""); | |
336 | formatter->dump_string("key", iter.key); | |
337 | formatter->dump_string("version_id", iter.version_id); | |
338 | formatter->dump_int("http_status", iter.http_status); | |
339 | formatter->dump_bool("error", iter.error); | |
340 | if (iter.error) { | |
341 | formatter->dump_string("error_message", iter.error_message); | |
342 | } else { | |
343 | formatter->dump_bool("delete_marker", iter.delete_marker); | |
344 | formatter->dump_string("marker_version_id", iter.marker_version_id); | |
345 | } | |
346 | formatter->close_section(); | |
347 | } | |
348 | formatter->close_section(); | |
349 | formatter->close_section(); | |
350 | } | |
7c673cae FG |
351 | formatter->close_section(); |
352 | } | |
353 | ||
a4b75251 TL |
354 | OpsLogManifold::~OpsLogManifold() |
355 | { | |
356 | for (const auto &sink : sinks) { | |
357 | delete sink; | |
358 | } | |
359 | } | |
360 | ||
361 | void OpsLogManifold::add_sink(OpsLogSink* sink) | |
362 | { | |
363 | sinks.push_back(sink); | |
364 | } | |
365 | ||
1e59de90 | 366 | int OpsLogManifold::log(req_state* s, struct rgw_log_entry& entry) |
a4b75251 TL |
367 | { |
368 | int ret = 0; | |
369 | for (const auto &sink : sinks) { | |
370 | if (sink->log(s, entry) < 0) { | |
371 | ret = -1; | |
372 | } | |
373 | } | |
374 | return ret; | |
375 | } | |
376 | ||
377 | OpsLogFile::OpsLogFile(CephContext* cct, std::string& path, uint64_t max_data_size) : | |
2a845540 | 378 | cct(cct), data_size(0), max_data_size(max_data_size), path(path), need_reopen(false) |
a4b75251 TL |
379 | { |
380 | } | |
381 | ||
2a845540 TL |
382 | void OpsLogFile::reopen() { |
383 | need_reopen = true; | |
384 | } | |
385 | ||
a4b75251 TL |
386 | void OpsLogFile::flush() |
387 | { | |
a4b75251 | 388 | { |
33c7a0ef | 389 | std::scoped_lock log_lock(mutex); |
a4b75251 TL |
390 | assert(flush_buffer.empty()); |
391 | flush_buffer.swap(log_buffer); | |
392 | data_size = 0; | |
393 | } | |
394 | for (auto bl : flush_buffer) { | |
395 | int try_num = 0; | |
396 | while (true) { | |
2a845540 TL |
397 | if (!file.is_open() || need_reopen) { |
398 | need_reopen = false; | |
399 | file.close(); | |
400 | file.open(path, std::ofstream::app); | |
401 | } | |
a4b75251 TL |
402 | bl.write_stream(file); |
403 | if (!file) { | |
404 | ldpp_dout(this, 0) << "ERROR: failed to log RGW ops log file entry" << dendl; | |
405 | file.clear(); | |
406 | if (stopped) { | |
407 | break; | |
408 | } | |
409 | int sleep_time_secs = std::min((int) pow(2, try_num), 60); | |
410 | std::this_thread::sleep_for(std::chrono::seconds(sleep_time_secs)); | |
411 | try_num++; | |
412 | } else { | |
413 | break; | |
414 | } | |
415 | } | |
416 | } | |
417 | flush_buffer.clear(); | |
418 | file << std::endl; | |
419 | } | |
420 | ||
421 | void* OpsLogFile::entry() { | |
33c7a0ef | 422 | std::unique_lock lock(mutex); |
a4b75251 TL |
423 | while (!stopped) { |
424 | if (!log_buffer.empty()) { | |
425 | lock.unlock(); | |
426 | flush(); | |
427 | lock.lock(); | |
428 | continue; | |
429 | } | |
33c7a0ef | 430 | cond.wait(lock); |
a4b75251 | 431 | } |
33c7a0ef | 432 | lock.unlock(); |
a4b75251 TL |
433 | flush(); |
434 | return NULL; | |
435 | } | |
436 | ||
437 | void OpsLogFile::start() { | |
438 | stopped = false; | |
439 | create("ops_log_file"); | |
440 | } | |
441 | ||
442 | void OpsLogFile::stop() { | |
443 | { | |
33c7a0ef TL |
444 | std::unique_lock lock(mutex); |
445 | cond.notify_one(); | |
a4b75251 TL |
446 | stopped = true; |
447 | } | |
448 | join(); | |
449 | } | |
450 | ||
451 | OpsLogFile::~OpsLogFile() | |
452 | { | |
453 | if (!stopped) { | |
454 | stop(); | |
455 | } | |
456 | file.close(); | |
457 | } | |
458 | ||
1e59de90 | 459 | int OpsLogFile::log_json(req_state* s, bufferlist& bl) |
a4b75251 | 460 | { |
33c7a0ef | 461 | std::unique_lock lock(mutex); |
a4b75251 TL |
462 | if (data_size + bl.length() >= max_data_size) { |
463 | ldout(s->cct, 0) << "ERROR: RGW ops log file buffer too full, dropping log for txn: " << s->trans_id << dendl; | |
464 | return -1; | |
465 | } | |
466 | log_buffer.push_back(bl); | |
467 | data_size += bl.length(); | |
33c7a0ef | 468 | cond.notify_all(); |
a4b75251 TL |
469 | return 0; |
470 | } | |
471 | ||
1e59de90 TL |
472 | unsigned OpsLogFile::get_subsys() const { |
473 | return dout_subsys; | |
474 | } | |
475 | ||
a4b75251 TL |
476 | JsonOpsLogSink::JsonOpsLogSink() { |
477 | formatter = new JSONFormatter; | |
478 | } | |
479 | ||
480 | JsonOpsLogSink::~JsonOpsLogSink() { | |
481 | delete formatter; | |
482 | } | |
483 | ||
484 | void JsonOpsLogSink::formatter_to_bl(bufferlist& bl) | |
7c673cae FG |
485 | { |
486 | stringstream ss; | |
487 | formatter->flush(ss); | |
488 | const string& s = ss.str(); | |
7c673cae FG |
489 | bl.append(s); |
490 | } | |
491 | ||
1e59de90 | 492 | int JsonOpsLogSink::log(req_state* s, struct rgw_log_entry& entry) |
a4b75251 TL |
493 | { |
494 | bufferlist bl; | |
495 | ||
496 | lock.lock(); | |
497 | rgw_format_ops_log_entry(entry, formatter); | |
498 | formatter_to_bl(bl); | |
499 | lock.unlock(); | |
500 | ||
501 | return log_json(s, bl); | |
502 | } | |
503 | ||
7c673cae FG |
504 | void OpsLogSocket::init_connection(bufferlist& bl) |
505 | { | |
506 | bl.append("["); | |
507 | } | |
508 | ||
9f95a23c | 509 | OpsLogSocket::OpsLogSocket(CephContext *cct, uint64_t _backlog) : OutputDataSocket(cct, _backlog) |
7c673cae | 510 | { |
7c673cae FG |
511 | delim.append(",\n"); |
512 | } | |
513 | ||
1e59de90 | 514 | int OpsLogSocket::log_json(req_state* s, bufferlist& bl) |
7c673cae | 515 | { |
a4b75251 TL |
516 | append_output(bl); |
517 | return 0; | |
7c673cae FG |
518 | } |
519 | ||
1e59de90 | 520 | OpsLogRados::OpsLogRados(rgw::sal::Driver* const& driver): driver(driver) |
7c673cae | 521 | { |
a4b75251 TL |
522 | } |
523 | ||
1e59de90 | 524 | int OpsLogRados::log(req_state* s, struct rgw_log_entry& entry) |
a4b75251 TL |
525 | { |
526 | if (!s->cct->_conf->rgw_ops_log_rados) { | |
527 | return 0; | |
528 | } | |
7c673cae | 529 | bufferlist bl; |
a4b75251 | 530 | encode(entry, bl); |
7c673cae | 531 | |
a4b75251 TL |
532 | struct tm bdt; |
533 | time_t t = req_state::Clock::to_time_t(entry.time); | |
534 | if (s->cct->_conf->rgw_log_object_name_utc) | |
535 | gmtime_r(&t, &bdt); | |
536 | else | |
537 | localtime_r(&t, &bdt); | |
a4b75251 TL |
538 | string oid = render_log_object_name(s->cct->_conf->rgw_log_object_name, &bdt, |
539 | entry.bucket_id, entry.bucket); | |
1e59de90 | 540 | if (driver->log_op(s, oid, bl) < 0) { |
20effc67 TL |
541 | ldpp_dout(s, 0) << "ERROR: failed to log RADOS RGW ops log entry for txn: " << s->trans_id << dendl; |
542 | return -1; | |
a4b75251 | 543 | } |
20effc67 | 544 | return 0; |
7c673cae FG |
545 | } |
546 | ||
1e59de90 | 547 | int rgw_log_op(RGWREST* const rest, req_state *s, const RGWOp* op, OpsLogSink *olog) |
7c673cae FG |
548 | { |
549 | struct rgw_log_entry entry; | |
550 | string bucket_id; | |
39ae355f | 551 | string op_name = (op ? op->name() : "unknown"); |
7c673cae FG |
552 | |
553 | if (s->enable_usage_log) | |
554 | log_usage(s, op_name); | |
555 | ||
556 | if (!s->enable_ops_log) | |
557 | return 0; | |
558 | ||
559 | if (s->bucket_name.empty()) { | |
20effc67 | 560 | /* this case is needed for, e.g., list_buckets */ |
7c673cae | 561 | } else { |
20effc67 TL |
562 | if (s->err.ret == -ERR_NO_SUCH_BUCKET || |
563 | rgw::sal::Bucket::empty(s->bucket.get())) { | |
564 | if (!s->cct->_conf->rgw_log_nonexistent_bucket) { | |
565 | ldout(s->cct, 5) << "bucket " << s->bucket_name << " doesn't exist, not logging" << dendl; | |
566 | return 0; | |
567 | } | |
568 | bucket_id = ""; | |
569 | } else { | |
570 | bucket_id = s->bucket->get_bucket_id(); | |
571 | } | |
572 | entry.bucket = rgw_make_bucket_entry_name(s->bucket_tenant, s->bucket_name); | |
7c673cae | 573 | |
20effc67 TL |
574 | if (check_utf8(entry.bucket.c_str(), entry.bucket.size()) != 0) { |
575 | ldpp_dout(s, 5) << "not logging op on bucket with non-utf8 name" << dendl; | |
576 | return 0; | |
577 | } | |
7c673cae | 578 | |
20effc67 TL |
579 | if (!rgw::sal::Object::empty(s->object.get())) { |
580 | entry.obj = s->object->get_key(); | |
581 | } else { | |
582 | entry.obj = rgw_obj_key("-"); | |
583 | } | |
7c673cae | 584 | |
20effc67 TL |
585 | entry.obj_size = s->obj_size; |
586 | } /* !bucket empty */ | |
7c673cae FG |
587 | |
588 | if (s->cct->_conf->rgw_remote_addr_param.length()) | |
589 | set_param_str(s, s->cct->_conf->rgw_remote_addr_param.c_str(), | |
590 | entry.remote_addr); | |
591 | else | |
592 | set_param_str(s, "REMOTE_ADDR", entry.remote_addr); | |
593 | set_param_str(s, "HTTP_USER_AGENT", entry.user_agent); | |
b32b8144 FG |
594 | // legacy apps are still using misspelling referer, such as curl -e option |
595 | if (s->info.env->exists("HTTP_REFERRER")) | |
596 | set_param_str(s, "HTTP_REFERRER", entry.referrer); | |
597 | else | |
598 | set_param_str(s, "HTTP_REFERER", entry.referrer); | |
599 | ||
94b18763 FG |
600 | std::string uri; |
601 | if (s->info.env->exists("REQUEST_METHOD")) { | |
602 | uri.append(s->info.env->get("REQUEST_METHOD")); | |
603 | uri.append(" "); | |
b32b8144 FG |
604 | } |
605 | ||
94b18763 FG |
606 | if (s->info.env->exists("REQUEST_URI")) { |
607 | uri.append(s->info.env->get("REQUEST_URI")); | |
608 | } | |
609 | ||
1e59de90 TL |
610 | /* Formerly, we appended QUERY_STRING to uri, but in RGW, QUERY_STRING is a |
611 | * substring of REQUEST_URI--appending qs to uri here duplicates qs to the | |
612 | * ops log */ | |
94b18763 FG |
613 | |
614 | if (s->info.env->exists("HTTP_VERSION")) { | |
615 | uri.append(" "); | |
616 | uri.append("HTTP/"); | |
617 | uri.append(s->info.env->get("HTTP_VERSION")); | |
618 | } | |
b32b8144 FG |
619 | |
620 | entry.uri = std::move(uri); | |
621 | ||
92f5a8d4 | 622 | entry.op = op_name; |
39ae355f TL |
623 | if (op) { |
624 | op->write_ops_log_entry(entry); | |
625 | } | |
7c673cae | 626 | |
20effc67 TL |
627 | if (s->auth.identity) { |
628 | entry.identity_type = s->auth.identity->get_identity_type(); | |
2a845540 | 629 | s->auth.identity->write_ops_log_entry(entry); |
20effc67 TL |
630 | } else { |
631 | entry.identity_type = TYPE_NONE; | |
632 | } | |
633 | ||
adb31ebb TL |
634 | if (! s->token_claims.empty()) { |
635 | entry.token_claims = std::move(s->token_claims); | |
636 | } | |
637 | ||
7c673cae FG |
638 | /* custom header logging */ |
639 | if (rest) { | |
640 | if (rest->log_x_headers()) { | |
641 | for (const auto& iter : s->info.env->get_map()) { | |
642 | if (rest->log_x_header(iter.first)) { | |
643 | entry.x_headers.insert( | |
644 | rgw_log_entry::headers_map::value_type(iter.first, iter.second)); | |
645 | } | |
646 | } | |
647 | } | |
648 | } | |
649 | ||
9f95a23c | 650 | entry.user = s->user->get_id().to_str(); |
f51cf556 TL |
651 | entry.object_owner = s->object_acl.get_owner().id; |
652 | entry.bucket_owner = s->bucket_owner.id; | |
7c673cae FG |
653 | |
654 | uint64_t bytes_sent = ACCOUNTING_IO(s)->get_bytes_sent(); | |
655 | uint64_t bytes_received = ACCOUNTING_IO(s)->get_bytes_received(); | |
656 | ||
657 | entry.time = s->time; | |
11fdf7f2 | 658 | entry.total_time = s->time_elapsed(); |
7c673cae FG |
659 | entry.bytes_sent = bytes_sent; |
660 | entry.bytes_received = bytes_received; | |
661 | if (s->err.http_ret) { | |
662 | char buf[16]; | |
663 | snprintf(buf, sizeof(buf), "%d", s->err.http_ret); | |
664 | entry.http_status = buf; | |
a4b75251 | 665 | } else { |
7c673cae | 666 | entry.http_status = "200"; // default |
a4b75251 | 667 | } |
31f18b77 | 668 | entry.error_code = s->err.err_code; |
7c673cae | 669 | entry.bucket_id = bucket_id; |
9f95a23c | 670 | entry.trans_id = s->trans_id; |
7c673cae | 671 | if (olog) { |
a4b75251 | 672 | return olog->log(s, entry); |
7c673cae | 673 | } |
a4b75251 | 674 | return 0; |
7c673cae | 675 | } |
20effc67 TL |
676 | |
677 | void rgw_log_entry::generate_test_instances(list<rgw_log_entry*>& o) | |
678 | { | |
679 | rgw_log_entry *e = new rgw_log_entry; | |
f51cf556 TL |
680 | e->object_owner = parse_owner("object_owner"); |
681 | e->bucket_owner = parse_owner("bucket_owner"); | |
20effc67 TL |
682 | e->bucket = "bucket"; |
683 | e->remote_addr = "1.2.3.4"; | |
684 | e->user = "user"; | |
685 | e->obj = rgw_obj_key("obj"); | |
686 | e->uri = "http://uri/bucket/obj"; | |
687 | e->http_status = "200"; | |
688 | e->error_code = "error_code"; | |
689 | e->bytes_sent = 1024; | |
690 | e->bytes_received = 512; | |
691 | e->obj_size = 2048; | |
692 | e->user_agent = "user_agent"; | |
693 | e->referrer = "referrer"; | |
694 | e->bucket_id = "10"; | |
695 | e->trans_id = "trans_id"; | |
696 | e->identity_type = TYPE_RGW; | |
f51cf556 TL |
697 | e->account_id = "account_id"; |
698 | e->role_id = "role_id"; | |
20effc67 TL |
699 | o.push_back(e); |
700 | o.push_back(new rgw_log_entry); | |
701 | } | |
702 | ||
703 | void rgw_log_entry::dump(Formatter *f) const | |
704 | { | |
f51cf556 TL |
705 | f->dump_string("object_owner", to_string(object_owner)); |
706 | f->dump_string("bucket_owner", to_string(bucket_owner)); | |
20effc67 TL |
707 | f->dump_string("bucket", bucket); |
708 | f->dump_stream("time") << time; | |
709 | f->dump_string("remote_addr", remote_addr); | |
710 | f->dump_string("user", user); | |
711 | f->dump_stream("obj") << obj; | |
712 | f->dump_string("op", op); | |
713 | f->dump_string("uri", uri); | |
714 | f->dump_string("http_status", http_status); | |
715 | f->dump_string("error_code", error_code); | |
716 | f->dump_unsigned("bytes_sent", bytes_sent); | |
717 | f->dump_unsigned("bytes_received", bytes_received); | |
718 | f->dump_unsigned("obj_size", obj_size); | |
719 | f->dump_stream("total_time") << total_time; | |
720 | f->dump_string("user_agent", user_agent); | |
721 | f->dump_string("referrer", referrer); | |
722 | f->dump_string("bucket_id", bucket_id); | |
723 | f->dump_string("trans_id", trans_id); | |
724 | f->dump_unsigned("identity_type", identity_type); | |
f51cf556 TL |
725 | if (!account_id.empty()) { |
726 | f->dump_string("account_id", account_id); | |
727 | } | |
728 | if (!role_id.empty()) { | |
729 | f->dump_string("role_id", role_id); | |
730 | } | |
20effc67 | 731 | } |