1 /// Global logger module 2 module tagion.logger.Logger; 3 4 import core.sys.posix.pthread; 5 import syslog = core.sys.posix.syslog; 6 import std.format; 7 import std.string; 8 import tagion.basic.Types : Control; 9 import tagion.basic.Version : ver; 10 import tagion.hibon.Document : Document; 11 import tagion.hibon.HiBONJSON; 12 import tagion.hibon.HiBONRecord; 13 import tagion.logger.LogRecords; 14 import tagion.utils.pretend_safe_concurrency; 15 16 /// Is a but mask for the logger 17 enum LogLevel { 18 NONE = 0, /// No log is e 19 INFO = 1, /// Enable info logs 20 TRACE = INFO << 1, /// Enable trace logs 21 WARN = TRACE << 1, /// Enable warning 22 ERROR = WARN << 1, /// Enable errors 23 FATAL = ERROR << 1, /// Enable fatal 24 ALL = INFO | TRACE | WARN | ERROR | FATAL, /// Enable all types 25 STDERR = WARN | ERROR | FATAL 26 } 27 28 private static Tid logger_tid; /// In multi-threading mode this Tid is used 29 30 /// Logger used one for each thread 31 @safe 32 static struct Logger { 33 34 import std.format; 35 36 protected { 37 string _task_name; /// The name of the task using the logger 38 uint[] masks; /// Logger mask stack 39 __gshared string logger_task_name; /// Logger task name 40 __gshared Tid logger_subscription_tid; 41 42 } 43 44 /// Get task_name 45 @property 46 string task_name() @nogc @safe nothrow const { 47 return _task_name; 48 } 49 50 /* 51 * Sets the actor/log task_name 52 * Returns: false the task_name could not be set 53 */ 54 @property 55 bool task_name(const string name) @safe nothrow { 56 push(LogLevel.ALL); 57 scope (exit) { 58 pop(); 59 } 60 try { 61 locateLoggerTask(); 62 63 const registered = locate(name); 64 const i_am_the_registered = registered is thisTid; 65 if (registered is Tid.init) { 66 register(name, thisTid); 67 _task_name = name; 68 setThreadName(name); 69 return true; 70 } 71 else if (i_am_the_registered) { 72 _task_name = name; 73 return true; 74 } 75 else { 76 return false; 77 } 78 } 79 catch (Exception e) { 80 return false; 81 } 82 } 83 84 shared bool silent; /// If true the log is silened (no logs is process from any tasks) 85 86 /** 87 Sets the task name of the logger for the whole program 88 Note should be set in the logger task when the logger task 89 is ready and has been started correctly 90 */ 91 @trusted @nogc 92 void set_logger_task(string logger_task_name) nothrow 93 in { 94 assert(this.logger_task_name.length == 0); 95 } 96 do { 97 this.logger_task_name = logger_task_name; 98 } 99 100 /** 101 Returns: true if the task_name has been register by the logger 102 */ 103 @safe 104 bool isLoggerServiceRegistered() const nothrow { 105 return logger_tid !is Tid.init; 106 } 107 108 private void locateLoggerTask() @trusted const { 109 if (!isLoggerServiceRegistered) { 110 logger_tid = locate(logger_task_name); 111 } 112 } 113 114 @trusted 115 void registerSubscriptionTask(string task_name) { 116 logger_subscription_tid = locate(task_name); 117 } 118 119 @trusted 120 bool isLoggerSubRegistered() nothrow { 121 return logger_subscription_tid !is Tid.init; 122 } 123 124 /** 125 Push the current logger mask to the mask stack 126 */ 127 void push(const uint mask) nothrow { 128 masks ~= mask; 129 } 130 131 /** 132 Pops the current logger mask 133 Returns: the current mask 134 */ 135 @nogc 136 uint pop() nothrow { 137 uint result = masks[$ - 1]; 138 if (masks.length > 1) { 139 masks = masks[0 .. $ - 1]; 140 } 141 return result; 142 } 143 144 /** 145 Reports the text to the logger with the level LogLevel 146 */ 147 @trusted 148 void report(const LogLevel level, lazy scope string text) const nothrow { 149 version (unittest) 150 return; 151 if ((masks.length > 0) && (level & masks[$ - 1]) && !silent) { 152 import std.conv : to; 153 import std.exception : assumeWontThrow; 154 155 if (level & LogLevel.STDERR) { 156 import core.stdc.stdio; 157 158 scope const _level = assumeWontThrow(level.to!string); 159 scope const _text = toStringz(assumeWontThrow(text)); 160 stderr.fprintf("%.*s:%.*s: %s\n", 161 cast(int) _task_name.length, _task_name.ptr, 162 cast(int) _level.length, _level.ptr, 163 _text); 164 } 165 166 if (!isLoggerServiceRegistered) { 167 import core.stdc.stdio; 168 169 scope const _level = assumeWontThrow(level.to!string); 170 scope const _text = toStringz(assumeWontThrow(text)); 171 if (_task_name.length > 0) { 172 // printf("ERROR: Logger not register for '%.*s'\n", cast(int) _task_name.length, _task_name 173 // .ptr); 174 } 175 printf("%.*s:%.*s: %s\n", 176 cast(int) _task_name.length, _task_name.ptr, 177 cast(int) _level.length, _level.ptr, 178 _text); 179 } 180 else { 181 try { 182 immutable info = LogInfo(task_name, level); 183 immutable doc = TextLog(text).toDoc; 184 logger_tid.send(info, doc); 185 } 186 catch (Exception e) { 187 import std.stdio; 188 189 assumeWontThrow({ stderr.writefln("\t%s:%s: %s", task_name, level, text); stderr.writefln("%s", e); }()); 190 } 191 } 192 } 193 } 194 195 /// Conditional subscription logging 196 @trusted 197 void report(Topic topic, lazy string identifier, lazy const(Document) data) const nothrow { 198 // report(LogLevel.INFO, "%s|%s| %s", topic.name, identifier, data.toPretty); 199 if (topic.subscribed && log.isLoggerSubRegistered) { 200 try { 201 auto info = LogInfo(topic, task_name, identifier); 202 logger_subscription_tid.send(info, data); 203 } 204 catch (Exception e) { 205 import std.exception : assumeWontThrow; 206 import std.stdio; 207 208 assumeWontThrow({ 209 stderr.writefln("%s", e.msg); 210 stderr.writefln("\t%s:%s = %s", identifier, data.toPretty); 211 }()); 212 } 213 } 214 } 215 216 void opCall(Topic topic, lazy string identifier, lazy const(Document) data) const nothrow { 217 report(topic, identifier, data); 218 } 219 220 void opCall(T)(Topic topic, lazy string identifier, lazy T data) const nothrow if (isHiBONRecord!T) { 221 report(topic, identifier, data.toDoc); 222 } 223 224 void opCall(Topic topic, lazy string identifier) const nothrow { 225 report(topic, identifier, Document.init); 226 } 227 228 import std.traits : isBasicType; 229 230 void opCall(T)(Topic topic, lazy string identifier, lazy T data) const nothrow if (isBasicType!T && !is(T : void)) { 231 import tagion.hibon.HiBON; 232 233 if (topic.subscribed && log.isLoggerSubRegistered) { 234 try { 235 auto hibon = new HiBON; 236 hibon["data"] = data; 237 report(topic, identifier, Document(hibon)); 238 } 239 catch (Exception e) { 240 } 241 } 242 } 243 244 /** 245 formatted logger 246 */ 247 @trusted 248 void report(Args...)(LogLevel level, string fmt, lazy Args args) const nothrow { 249 report(level, format(fmt, args)); 250 } 251 252 /** 253 logs the text to in INFO level 254 */ 255 void opCall(lazy string text) const nothrow { 256 report(LogLevel.INFO, text); 257 } 258 259 /** 260 logs the fmt text in INFO level 261 */ 262 void opCall(Args...)(string fmt, lazy Args args) const nothrow { 263 report(LogLevel.INFO, fmt, args); 264 } 265 266 @trusted 267 void opCall(lazy const(Throwable) t) const nothrow { 268 import std.exception; 269 270 auto mt = assumeWontThrow(cast(Throwable) t); 271 272 fatal(assumeWontThrow(mt.toString)); 273 fatal(mt.info.toString); 274 } 275 276 void trace(lazy string text) const nothrow { 277 report(LogLevel.TRACE, text); 278 } 279 280 void trace(Args...)(string fmt, lazy Args args) const nothrow { 281 report(LogLevel.TRACE, fmt, args); 282 } 283 284 void warn(lazy string text) const nothrow { 285 report(LogLevel.WARN, text); 286 } 287 288 void warn(Args...)(string fmt, Args args) const nothrow { 289 report(LogLevel.WARN, fmt, args); 290 } 291 292 void error(lazy string text) const nothrow { 293 report(LogLevel.ERROR, text); 294 } 295 296 void error(Args...)(string fmt, lazy Args args) const nothrow { 297 report(LogLevel.ERROR, fmt, args); 298 } 299 300 void fatal(lazy string text) const nothrow { 301 report(LogLevel.FATAL, text); 302 } 303 304 void fatal(Args...)(string fmt, lazy Args args) const nothrow { 305 report(LogLevel.FATAL, fmt, args); 306 } 307 308 @trusted 309 void close() const nothrow { 310 if (isLoggerServiceRegistered) { 311 import std.exception : assumeWontThrow; 312 313 assumeWontThrow(logger_tid.send(Control.STOP)); 314 } 315 } 316 } 317 318 static Logger log; 319 320 import std.typecons; 321 322 @safe 323 struct Topic { 324 string name; 325 this(string name) pure nothrow { 326 this.name = name; 327 } 328 329 private const(Subscribed)* _subscribed; 330 private bool has_subscribed; 331 332 @property 333 bool subscribed() nothrow { 334 if (!has_subscribed) { 335 _subscribed = submask._register(name); 336 has_subscribed = true; 337 } 338 if (_subscribed is null) { 339 return false; 340 } 341 return (*_subscribed is Subscribed.yes); 342 } 343 344 } 345 346 alias Subscribed = shared(Flag!"subscribed"); 347 348 @safe 349 final synchronized class SubscriptionMask { 350 // yes|no topic 351 private Subscribed[string] _registered_topics; 352 353 private const(Subscribed)* _register(string topic) nothrow { 354 Subscribed* s = topic in _registered_topics; 355 if (s is null) { 356 _registered_topics[topic] = Subscribed.no; 357 s = topic in _registered_topics; 358 } 359 return s; 360 } 361 362 @trusted 363 void subscribe(string topic) { 364 if (thisTid == log.logger_subscription_tid) { 365 _registered_topics[topic] = Subscribed.yes; 366 return; 367 } 368 assert(0, "Only the logger subscription task can control the subscription"); 369 } 370 371 void subscribe(Topic topic) { 372 subscribe(topic.name); 373 } 374 375 @trusted 376 void unsubscribe(string topic) { 377 if (thisTid == log.logger_subscription_tid) { 378 _registered_topics[topic] = Subscribed.no; 379 return; 380 } 381 assert(0, "Only the logger subscription task can control the subscription"); 382 } 383 384 void unsubscribe(Topic topic) { 385 unsubscribe(topic.name); 386 } 387 388 } 389 390 static shared SubscriptionMask submask; 391 shared static this() { 392 submask = new SubscriptionMask(); 393 } 394 395 unittest { 396 import core.time; 397 398 Topic topic = Topic("some_tag"); 399 assert(!topic.subscribed, "Topic was subscribed, it shouldn't"); 400 register("log_sub_task", thisTid); 401 log.registerSubscriptionTask("log_sub_task"); 402 auto some_symbol = Document.init; 403 log(topic, "", some_symbol); 404 assert(false == receiveTimeout(Duration.zero, (LogInfo _, const(Document) __) {}), "Received an unsubscribed topic"); 405 submask.subscribe(topic.name); 406 assert(topic.subscribed, "Topic wasn't subscribed, it should"); 407 log(topic, "", some_symbol); 408 assert(true == receiveTimeout(Duration.zero, (LogInfo _, const(Document) __) {}), "Didn't receive subscribed topic"); 409 } 410 411 version (Posix) { 412 import core.sys.posix.pthread; 413 414 /* 415 * Note: non portable 416 * Altough implemented on most platforms, it might behave differently 417 */ 418 extern (C) int pthread_setname_np(pthread_t, const char*) nothrow; 419 420 // The max task name lenght is set when you compile your kernel, 421 // You might have set it differently 422 enum TASK_COMM_LEN = 16; 423 424 /** 425 * Set the thread name to the same as the task name 426 * Note. Makes it easier to debug because pthread name is the same as th task name 427 * Cuts of the name if longer than length allowed by the kernel 428 **/ 429 @trusted 430 int setThreadName(string _name) nothrow { 431 // dfmt off 432 string name = (_name.length < TASK_COMM_LEN) 433 ? _name ~ '\0' 434 : _name[0 .. TASK_COMM_LEN - 1] ~ '\0'; 435 // dfmt on 436 assert(name.length <= TASK_COMM_LEN); 437 return pthread_setname_np(pthread_self(), &name[0]); 438 } 439 440 @safe 441 unittest { 442 assert(setThreadName("antonio") == 0, "Could not set short thread name"); 443 assert(setThreadName("antoniofernandesthe3rd") == 0, "Could not set long thread name"); 444 } 445 } 446 else { 447 int setThreadName(string _) @safe nothrow { 448 return 0; 449 } 450 }