00001 /** @file 00002 00003 Logging 00004 00005 @section license License 00006 00007 Licensed to the Apache Software Foundation (ASF) under one 00008 or more contributor license agreements. See the NOTICE file 00009 distributed with this work for additional information 00010 regarding copyright ownership. The ASF licenses this file 00011 to you under the Apache License, Version 2.0 (the 00012 "License"); you may not use this file except in compliance 00013 with the License. You may obtain a copy of the License at 00014 00015 http://www.apache.org/licenses/LICENSE-2.0 00016 00017 Unless required by applicable law or agreed to in writing, software 00018 distributed under the License is distributed on an "AS IS" BASIS, 00019 WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 00020 See the License for the specific language governing permissions and 00021 limitations under the License. 00022 00023 @section design Logging Design 00024 00025 @verbatim 00026 o Configuration Variables (and sample values) 00027 00028 proxy.config.log.format_file logs/formats 00029 proxy.config.log.logging_enabled 1 00030 proxy.config.log.failsafe_logging_enabled 0 00031 proxy.config.log.sampling_interval 1 00032 proxy.config.log.buffer_segment_count 16 00033 proxy.config.log.buffer_segment_size 1MB 00034 proxy.config.log.max_entries_per_segment 100 00035 proxy.config.log.online_formats_enabled 0 00036 proxy.config.log.online_squid_format 0 00037 proxy.config.log.online_ns_common_format 0 00038 proxy.config.log.online_ns_ext_format 0 00039 proxy.config.log.online_ns_ext2_format 0 00040 proxy.config.log.filtering_enabled 0 00041 proxy.config.log.local_disk_enabled 2 (only if network fails) 00042 proxy.config.log.network_enabled 1 00043 proxy.config.log.network_port 4444 00044 proxy.config.log.network_timeout_ms 100 00045 proxy.config.log.lock_timeout_ms 10 00046 00047 o Memory Layout 00048 00049 Log data for each transaction is stored in a LogBufferEntry that has 00050 been allocated from a LogBufferSegment, which in-turn is located 00051 within a LogBufferPool. A LogBufferPool looks like: 00052 00053 +--++--++--+---+--+-----+--+--++--++--+----+--+---++--++...+ 00054 |ph||sh||eh|eee|eh|eeeee|eh|ee||sh||eh|eeee|eh|eee||sh|| | 00055 +--++--++--+---+--+-----+--+--++--++--+----+--+---++--++...+ 00056 ^ ^ ^ ^ 00057 | | | | 00058 | | | +-- actual data for a LogBufferEntry 00059 | | +----- a LogBufferEntryHeader describing the following entry 00060 | +--------- a LogBufferSegmentHeader describing the entries 00061 +------------- a LogBufferPoolHeader describing the segments 00062 00063 o Initial State 00064 00065 - A LogBufferPool is allocated, with storage equal to 00066 sizeof (LogBufferPoolHeader) + buffer_segment_count * buffer_segment_size 00067 00068 - The buffer pool space is divided into buffer_segment_count 00069 segments, each with a fixed size of buffer_segment_size. 00070 00071 - All of the segments are placed on the empty_segment list in the 00072 pool header (H), and the first segment is assigned as the 00073 current_segment. 00074 00075 o LogBuffer Allocation 00076 00077 - If logging is disabled (!proxy.config.log.logging_enabled), 00078 return Log::SKIP. 00079 00080 - If proxy.config.log.sampling_interval > 1 but it's not time to 00081 sample, return Log::SKIP. 00082 00083 - If proxy.config.log.filtering_enabled, then check host and domain 00084 in the request_header against the filter file. If this request does 00085 not pass the filter, return Log::SKIP. 00086 00087 - The pool_lock in the pool header is obtained. If it cannot be 00088 obtained after proxy.config.log.trylock_time_ms milliseconds, then 00089 a new pool is allocated and the lock is taken on the new pool. 00090 If a new pool cannot be allocated, then Log::FAIL is returned and 00091 the client (HttpStateMachineGet) can deal with the failure in the 00092 best possible way. 00093 00094 - If there is not enough space in the current segment, the current 00095 segment is moved to the full_segment list and a segment from the 00096 empty_segment list is designated as the current_segment. If there 00097 are no segments in the empty_segment list, the FAIL_MEMORY status 00098 is returned. 00099 00100 - The entry count for the current segment is bumped and the next 00101 offset value is computed and stored. 00102 00103 - The pool_lock is released. 00104 00105 - The c_request_timestamp field is set, ensuring that each of the 00106 entries within the segment are automatically ordered, and the 00107 LogBuffer pointer is returned. 00108 00109 o LogBuffer Completion 00110 00111 - Since each client thread now has a unique buffer pointer, all 00112 writes can occur concurrently and without additional locking. 00113 00114 - The logging data will be extracted from the LogAccessData object 00115 using the member functions within. Only those data items that will 00116 be needed will be taken. The data is then marshalled into the 00117 buffer previously allocated. 00118 00119 - The LogBuffer is composed of two parts: a fixed-size part that 00120 contains all of the statically-sized fields, and a variable-sized 00121 buffer that follows, containing all of the space for strings. 00122 Variable-size fields in the LogBuffer are actually just 00123 fixed-size offsets into the variable-size region. 00124 00125 +---------------------+ 00126 | fixed-size | 00127 +---------------------+ 00128 | | contains strings and any custom logging 00129 : variable-size : fields not in the union set. 00130 | | 00131 +---------------------+ 00132 00133 - Once the buffer has been completed, it is committed into the 00134 segment from which it was allocated by incrementing the 00135 commit_count within the segment header. This is an ATOMIC update 00136 so that no locking is required. If the commit_count is equal to 00137 the entry_count and the segment is on the full_list, then the 00138 logging thread will be awoken so that it can flush the segment 00139 to disk/net. 00140 00141 o Flushing 00142 00143 +-+---------------+ 00144 |h|bbb|b|bbbb|bbb | 00145 +-+---------------+ 00146 | 00147 | ********** +---------------+ 00148 +-?-> * format * ---> |abcdefghijklmno| ---> DISK 00149 | ********** +---------------+ 00150 | 00151 +-?-> DISK 00152 | 00153 +-?-> NETWORK 00154 00155 - The logging thread wakes up whenever there is a LogBufferSegment 00156 ready to be flushed. This occurs when it is on the full_segment 00157 list and the commit_count is the same as the entry_count. 00158 00159 - If proxy.config.log.online_formats_enabled is set, then the segment 00160 is passed through the formatting module, which creates ASCII buffers 00161 for the selected pre-defined formats. All ASCII buffers are then 00162 flushed to local disk using basic I/O primitives. The logging 00163 thead is allowed to block on I/O since logging buffers can be 00164 continually allocated without the assistance of the logging thread. 00165 00166 - If local disk logging is enabled, the complete binary segment 00167 structure is written to disk, and can be processed later with an 00168 off-line formatting tool. 00169 00170 - If network logging is enabled, the segment is written to the 00171 pre-defined network port. A timeout keeps this from being an 00172 unbounded operation. 00173 00174 - Once the segment has been passed through all possible output 00175 channels, it must be placed back onto the free_list in its pool. 00176 The LogBufferPool lock is then obtained. 00177 00178 - The evacuated segment is returned to the empty_segment list. 00179 00180 - If all of the segments are on the empty_segment list and there is 00181 at least one other pool around, then this pool will be deleted. 00182 Otherwsise, the LogBufferPool lock is released. 00183 00184 - If there are no more segments to be flushed, then the logging 00185 thread will go back to sleep (waiting on a condition variable). 00186 00187 o Off-line Processing 00188 00189 - In the default case, data written to disk will be in binary form, 00190 in units of a segment. An off-line processing tool, called logcat, 00191 can be written to read this data (as stdin) and generate formatted 00192 log entries (as stdout). Thus, this tool could be used as a pipe. 00193 00194 o Log Collation 00195 00196 - Log collation is managed by LogCollator nodes, which are 00197 stand-alone processes that receive LogBufferSegments from specified 00198 clients and merges them into larger, collated LogBufferSegments. 00199 At this point, the collated segments can be flushed as before. 00200 To ease the impact of the initial implementation on the manager, 00201 the collator will likely be implemented as a new thread within the 00202 proxy process on the node that will do the log collation. That 00203 means that this node will have to run the proxy, but we should see 00204 about being able to disable it from actually participating in the 00205 proxy cluster. 00206 00207 - Log collator processes attach to the network port for the client 00208 nodes they're receiving their logs from. A single collator can 00209 attach to any number of client nodes, and is responsible for 00210 keeping the network pipes clean so that log entries don't back up. 00211 00212 - Collation is accomplished with a merge-sort of the segments from 00213 each node, since segments from each node are guaranteed to be 00214 in-order. If, due to a timeout, the collator has to continue with 00215 the sort and later receives an out-of-order buffer, the data will 00216 be processed and an error will be generated indicating that the 00217 collated logs are out of order. A tool will be provided to 00218 re-order the entries in the event of a sorting error. 00219 00220 o Custom Log Formats 00221 00222 - Custom logging formats are possible, where the field selection is 00223 the "union" set of pre-defined log format fields plus any 00224 information from the HTTP headers. 00225 00226 - Log formats are specified using a printf-like format string, where 00227 the conversion codes (%) are replaced with the appropriate logging 00228 fields. Each of the union set fields will have its own conversion 00229 code (see LogBuffer below), and additional fields from a header 00230 will have the general form of %{field}header. 00231 00232 - Formats are specified in the log format file. 00233 00234 o Filtering 00235 00236 - Currently, filtering will only be supported based on exact matching 00237 of the host or domain name of the request. 00238 00239 - Filtering is specified in the log format file. 00240 00241 o Log Format File 00242 00243 - Each line of the log format file consists of four fields separated 00244 by whitespaces: 00245 00246 + identifier - used to identify this format/filter 00247 + filename - the name of the log file 00248 + (filter) - the filter to apply for this file 00249 + "format" - the format string for each entry 00250 00251 Filters have the form (field op value), where "field" can either be 00252 %shn (server host name) or %sdn (sever domain name); "op" can either 00253 be == or !=; and "value" can be any valid hostname or domain name, 00254 such as hoot.example.com or example.com. 00255 00256 - Sample entries in the log format file: 00257 00258 1 common () "%chi - %cun [%cqtf] \"%cqtx\" %pss %pcl" 00259 2 custom (%shn == hoot.example.com) "%cqu" 00260 @endverbatim 00261 00262 @section api External API 00263 00264 @verbatim 00265 int Log::access (LogAccess *entry); 00266 00267 The return value is Log::OK if all log objects successfully logged the 00268 entry. Otherwise, it has the following bits set to indicate what happened 00269 00270 ret_val & Log::SKIP - at least one object filtered the entry 00271 - transaction logging has been disabled 00272 - the logging system is sampling and it is 00273 not yet time for a new sample 00274 - no log objects have been defined 00275 - entry to log is empty 00276 00277 ret_val & Log::FAIL an internal limit of the logging system was 00278 exceeded preventing entry from being logged 00279 00280 ret_val & Log::FULL the logging space has been exhausted 00281 00282 @endverbatim 00283 00284 @section example Example usage of the API 00285 00286 @code 00287 LogAccessHttpSM entry (this); 00288 int ret = Log::access (&entry); 00289 @endcode 00290 00291 */ 00292 00293 #ifndef LOG_H 00294 #define LOG_H 00295 00296 #include <stdarg.h> 00297 #include "libts.h" 00298 #include "P_RecProcess.h" 00299 #include "LogFile.h" 00300 #include "LogBuffer.h" 00301 00302 class LogAccess; 00303 class LogFieldList; 00304 class LogFilterList; 00305 class LogFormatList; 00306 //class LogBufferList; vl: we don't need it here 00307 struct LogBufferHeader; 00308 class LogFile; 00309 class LogBuffer; 00310 class LogFormat; 00311 class LogObject; 00312 class LogConfig; 00313 class TextLogObject; 00314 00315 class LogFlushData 00316 { 00317 public: 00318 LINK(LogFlushData, link); 00319 Ptr<LogFile> m_logfile; 00320 LogBuffer *logbuffer; 00321 void *m_data; 00322 int m_len; 00323 00324 LogFlushData(LogFile *logfile, void *data, int len = -1): 00325 m_logfile(logfile), m_data(data), m_len(len) 00326 { 00327 } 00328 00329 ~LogFlushData() 00330 { 00331 switch (m_logfile->m_file_format) { 00332 case LOG_FILE_BINARY: 00333 logbuffer = (LogBuffer *)m_data; 00334 LogBuffer::destroy(logbuffer); 00335 break; 00336 case LOG_FILE_ASCII: 00337 case LOG_FILE_PIPE: 00338 free(m_data); 00339 break; 00340 case N_LOGFILE_TYPES: 00341 default: 00342 ink_release_assert(!"Unknown file format type!"); 00343 } 00344 } 00345 }; 00346 00347 /** 00348 This object exists to provide a namespace for the logging system. 00349 It contains all data types and global variables relevant to the 00350 logging system. You can't actually create a Log object, so all 00351 members are static. 00352 */ 00353 class Log 00354 { 00355 public: 00356 00357 enum ReturnCodeFlags 00358 { 00359 LOG_OK = 1, 00360 SKIP = 2, 00361 AGGR = 4, 00362 FAIL = 8, 00363 FULL = 16 00364 }; 00365 00366 enum LoggingMode 00367 { 00368 LOG_MODE_NONE = 0, 00369 LOG_MODE_ERRORS, // log *only* errors 00370 LOG_MODE_TRANSACTIONS, // log *only* transactions 00371 LOG_MODE_FULL 00372 }; 00373 00374 enum InitFlags 00375 { 00376 FIELDS_INITIALIZED = 1, 00377 FULLY_INITIALIZED = 2 00378 }; 00379 00380 enum ConfigFlags 00381 { 00382 NO_REMOTE_MANAGEMENT = 1, 00383 STANDALONE_COLLATOR = 2, 00384 LOGCAT = 4 00385 }; 00386 00387 enum CollationMode 00388 { 00389 NO_COLLATION = 0, 00390 COLLATION_HOST, 00391 SEND_STD_FMTS, 00392 SEND_NON_XML_CUSTOM_FMTS, 00393 SEND_STD_AND_NON_XML_CUSTOM_FMTS, 00394 N_COLLATION_MODES 00395 }; 00396 00397 enum RollingEnabledValues 00398 { 00399 NO_ROLLING = 0, 00400 ROLL_ON_TIME_ONLY, 00401 ROLL_ON_SIZE_ONLY, 00402 ROLL_ON_TIME_OR_SIZE, 00403 ROLL_ON_TIME_AND_SIZE, 00404 INVALID_ROLLING_VALUE 00405 }; 00406 00407 enum 00408 { 00409 MIN_ROLLING_INTERVAL_SEC = 60, // 5 minute minimum rolling interval 00410 MAX_ROLLING_INTERVAL_SEC = 86400 // 24 hrs rolling interval max 00411 }; 00412 00413 // main interface 00414 static void init(int configFlags = 0); 00415 static void init_fields(); 00416 inkcoreapi static bool transaction_logging_enabled() 00417 { 00418 return (logging_mode == LOG_MODE_FULL || logging_mode == LOG_MODE_TRANSACTIONS); 00419 } 00420 00421 inkcoreapi static bool error_logging_enabled() 00422 { 00423 return (logging_mode == LOG_MODE_FULL || logging_mode == LOG_MODE_ERRORS); 00424 } 00425 00426 inkcoreapi static int access(LogAccess * lad); 00427 inkcoreapi static int va_error(const char *format, va_list ap); 00428 inkcoreapi static int error(const char *format, ...) TS_PRINTFLIKE(1, 2); 00429 00430 // public data members 00431 inkcoreapi static LogObject *error_log; 00432 static LogConfig *config; 00433 static LogFieldList global_field_list; 00434 // static LogBufferList global_buffer_full_list; vl: not used 00435 // static LogBufferList global_buffer_delete_list; vl: not used 00436 static InkHashTable *field_symbol_hash; 00437 static LogFormat *global_scrap_format; 00438 static LogObject *global_scrap_object; 00439 static LoggingMode logging_mode; 00440 00441 // logging thread stuff 00442 static EventNotify *preproc_notify; 00443 static void *preproc_thread_main(void *args); 00444 static EventNotify *flush_notify; 00445 static InkAtomicList *flush_data_list; 00446 static void *flush_thread_main(void *args); 00447 00448 // collation thread stuff 00449 static EventNotify collate_notify; 00450 static ink_thread collate_thread; 00451 static int collation_preproc_threads; 00452 static int collation_accept_file_descriptor; 00453 static int collation_port; 00454 static void *collate_thread_main(void *args); 00455 static LogObject *match_logobject(LogBufferHeader * header); 00456 00457 // reconfiguration stuff 00458 static void change_configuration(); 00459 static int handle_logging_mode_change(const char *name, RecDataT data_type, RecData data, void *cookie); 00460 00461 Log(); // shut up stupid DEC C++ compiler 00462 00463 friend void RegressionTest_LogObjectManager_Transfer(RegressionTest *, int, int *); 00464 private: 00465 00466 static void periodic_tasks(long time_now); 00467 static void create_threads(); 00468 static void init_when_enabled(); 00469 00470 static int init_status; 00471 static int config_flags; 00472 static bool logging_mode_changed; 00473 00474 // -- member functions that are not allowed -- 00475 Log(const Log & rhs); 00476 Log & operator=(const Log & rhs); 00477 }; 00478 00479 00480 static inline bool 00481 LogRollingEnabledIsValid(int enabled) 00482 { 00483 return (enabled >= Log::NO_ROLLING || enabled < Log::INVALID_ROLLING_VALUE); 00484 } 00485 00486 #endif