{"action":"created","issue":{"url":"https://api.github.com/repos/friendica/friendica/issues/6354","repository_url":"https://api.github.com/repos/friendica/friendica","labels_url":"https://api.github.com/repos/friendica/friendica/issues/6354/labels{/name}","comments_url":"https://api.github.com/repos/friendica/friendica/issues/6354/comments","events_url":"https://api.github.com/repos/friendica/friendica/issues/6354/events","html_url":"https://github.com/friendica/friendica/pull/6354","id":394901327,"node_id":"MDExOlB1bGxSZXF1ZXN0MjQxNTA4NzE5","number":6354,"title":"[WIP] Add monolog","user":{"login":"nupplaphil","id":379654,"node_id":"MDQ6VXNlcjM3OTY1NA==","avatar_url":"https://avatars3.githubusercontent.com/u/379654?v=4","gravatar_id":"","url":"https://api.github.com/users/nupplaphil","html_url":"https://github.com/nupplaphil","followers_url":"https://api.github.com/users/nupplaphil/followers","following_url":"https://api.github.com/users/nupplaphil/following{/other_user}","gists_url":"https://api.github.com/users/nupplaphil/gists{/gist_id}","starred_url":"https://api.github.com/users/nupplaphil/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/nupplaphil/subscriptions","organizations_url":"https://api.github.com/users/nupplaphil/orgs","repos_url":"https://api.github.com/users/nupplaphil/repos","events_url":"https://api.github.com/users/nupplaphil/events{/privacy}","received_events_url":"https://api.github.com/users/nupplaphil/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":6,"created_at":"2018-12-30T21:04:34Z","updated_at":"2019-01-01T20:58:12Z","closed_at":null,"author_association":"NONE","pull_request":{"url":"https://api.github.com/repos/friendica/friendica/pulls/6354","html_url":"https://github.com/friendica/friendica/pull/6354","diff_url":"https://github.com/friendica/friendica/pull/6354.diff","patch_url":"https://github.com/friendica/friendica/pull/6354.patch"},"body":"# **[WIP]**\r\n\r\nThis is an idea how we can improve the logging of Friendica.\r\nWhy I did it \"this way\":\r\n- [Monolog](https://github.com/Seldaek/monolog) was chosen by a lot of state-of-the-art frameworks and seems fast and small enough\r\n- ~We can now use Logging even without having a logfile or an App instance (f.e. during installation, daemon start) - afaik it currently leads to infinite loops~ (outdated)\r\n- We can now handle different outputs at the same time (f.e. logging to file, stdout, syslog, ...)\r\n- Tagging the logs make it easier to find things ('action' => 'login', 'module' => 'api', ...)\r\n- Creating PSR-3 compliant loglevels (info, debug, error, warning, fatal, ..) leads to a standard behaviour for logging (see https://github.com/Seldaek/monolog/blob/master/doc/01-usage.md#log-levels ) - I think the description will lead to a better understanding which loglevel is needed for particular output\r\n- Future proof if somebody likes to send the log to other services (f.e. mail warnings, slack infos, elastic search tagging, ...)\r\n\r\nI started the refactoring because I tried to output the log to `friendica.log` and STDOUT at the same time (for the docker project of course ;-) ).\r\n\r\nAn example-output currently is:\r\n```console\r\n[2018-12-30 21:14:06] app.INFO: api_get_user: Fetching user data {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":528,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:06] app.INFO: api_get_user: getting user {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":612,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:06] app.INFO: api_get_user: found user {\"module\":\"api\",\"action\":\"get_user\",\"user\":42,\"extra_query\":\"AND `contact`.`uid` = %d AND `contact`.`self` \"} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":624,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:06] app.INFO: api_get_user: Fetching user data {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":528,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:06] app.INFO: api_get_user: getting user {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":612,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:06] app.INFO: api_get_user: found user {\"module\":\"api\",\"action\":\"get_user\",\"user\":42,\"extra_query\":\"AND `contact`.`uid` = %d AND `contact`.`self` \"} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":624,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:08] app.INFO: api_get_user: Fetching user data {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":528,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:08] app.INFO: api_get_user: getting user {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":612,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:08] app.INFO: api_get_user: found user {\"module\":\"api\",\"action\":\"get_user\",\"user\":42,\"extra_query\":\"AND `contact`.`uid` = %d AND `contact`.`self` \"} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":624,\"class\":null,\"function\":\"api_get_user\"}\r\n..[2018-12-30 21:14:15] app.INFO: api_get_user: Fetching user data {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":528,\"class\":null,\"function\":\"api_get_user\"}\r\n[2018-12-30 21:14:15] app.INFO: api_get_user: getting user {\"module\":\"api\",\"action\":\"get_user\",\"user\":null} {\"app_id\":\"log:4542:5c29334a2d5d76161\",\"process_id\":4542,\"file\":\"/home/travis/build/friendica/friendica/include/api.php\",\"line\":612,\"class\":null,\"function\":\"api_get_user\"}\r\n```\r\n\r\nThe output is explained in [Message structure](https://github.com/Seldaek/monolog/blob/master/doc/message-structure.md);\r\n\r\nSome future steps after the refactoring of the Logging would be:\r\n- Adding options to the admin-panel to choose what to do with the logs (see [Handlers](https://github.com/Seldaek/monolog/blob/master/doc/02-handlers-formatters-processors.md#handlers) for some possibilities)\r\n- Adding standard-tags for functions (f.e. 'module' => $currentModule by default)\r\n- ..\r\n\r\nI know that @annando won't like the `$a->getLogger()` thing, but if needed  we can do something like:\r\n```php\r\nLogger::debug($msg)\r\n{\r\n    $app = self::getApp();\r\n    $app->getLogger()->debug($msg);\r\n}\r\n```\r\nwhich will encapsulate the call.\r\n\r\nAnother way could be:\r\n```php\r\nLogger::log($msg, $loglevel)\r\n{\r\n    $app = self::getApp();\r\n    $app->getLogger()->log($msg, $level);\r\n}\r\n```\r\n\r\nI'm open for discussions. Hopefully it wasn't just a waste of time ;-)\r\n\r\n [edit] copied test-api-output "},"comment":{"url":"https://api.github.com/repos/friendica/friendica/issues/comments/450756422","html_url":"https://github.com/friendica/friendica/pull/6354#issuecomment-450756422","issue_url":"https://api.github.com/repos/friendica/friendica/issues/6354","id":450756422,"node_id":"MDEyOklzc3VlQ29tbWVudDQ1MDc1NjQyMg==","user":{"login":"nupplaphil","id":379654,"node_id":"MDQ6VXNlcjM3OTY1NA==","avatar_url":"https://avatars3.githubusercontent.com/u/379654?v=4","gravatar_id":"","url":"https://api.github.com/users/nupplaphil","html_url":"https://github.com/nupplaphil","followers_url":"https://api.github.com/users/nupplaphil/followers","following_url":"https://api.github.com/users/nupplaphil/following{/other_user}","gists_url":"https://api.github.com/users/nupplaphil/gists{/gist_id}","starred_url":"https://api.github.com/users/nupplaphil/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/nupplaphil/subscriptions","organizations_url":"https://api.github.com/users/nupplaphil/orgs","repos_url":"https://api.github.com/users/nupplaphil/repos","events_url":"https://api.github.com/users/nupplaphil/events{/privacy}","received_events_url":"https://api.github.com/users/nupplaphil/received_events","type":"User","site_admin":false},"created_at":"2019-01-01T20:58:12Z","updated_at":"2019-01-01T20:58:12Z","author_association":"NONE","body":"The current output for all (legacy) logs:\r\n\r\n```console\r\n[...]\r\n2019-01-01 20:46:58 worker [INFO]: updating structure for table workerqueue ... [] []\r\n2019-01-01 20:46:58 worker [INFO]: Update from '1293'  to '1294' - finished [] []\r\n2019-01-01 20:46:58 worker [INFO]: Update function 'update_1294' - start [] []\r\n2019-01-01 20:46:58 worker [INFO]: Path \"/tmp/localhost\" is not writable for user www-data [] []\r\n2019-01-01 20:46:58 worker [NOTICE]: gender fix completed {\"action\":\"update\",\"translateKey\":\"gender\",\"Success\":0,\"Fail\":0} []\r\n2019-01-01 20:46:58 worker [NOTICE]: marital fix completed {\"action\":\"update\",\"translateKey\":\"marital\",\"Success\":0,\"Fail\":0} []\r\n2019-01-01 20:46:58 worker [NOTICE]: sexual fix completed {\"action\":\"update\",\"translateKey\":\"sexual\",\"Success\":0,\"Fail\":0} []\r\n2019-01-01 20:46:58 worker [INFO]: Update function 'update_1294' - finished [] []\r\n2019-01-01 20:46:58 worker [INFO]: Update from '1293'  to '1294' - successful [] []\r\n2019-01-01 20:46:58 worker [INFO]: Parameter mismatch. Query \"SELECT `uid`, `language`, `email` FROM `user` WHERE (`email` IN (%s))\" - Parameters Array (     [1] => 'admin@friendica.local' )  [] []\r\n2019-01-01 20:46:58 worker [WARNING]: DB Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '%s))' at line 1 DBA::select, Update::updateSuccessfull, Update::run, DBUpdate::execute, Worker::execFunction, Worker::execute, Worker::processQueue SELECT `uid`, `language`, `email` FROM `user` WHERE (`email` IN (%s)) [] []\r\n2019-01-01 20:46:58 worker [NOTICE]: Database structure update successful. [] []\r\n2019-01-01 20:46:58 worker [INFO]: DB: 0.00 - Lock: 0.01 - Rest: 0.02 - Execution: 0.20 [] []\r\n2019-01-01 20:46:58 worker [WARNING]: Process 3092 - Prio 10 - ID 1: DBUpdate - done in 0.20060801506042 seconds. Process PID: wrk:3092:5c2bd1c2acef82070 [] []\r\n2019-01-01 20:46:58 worker [INFO]: Path \"/tmp/localhost\" is not writable for user www-data [] []\r\n2019-01-01 20:46:58 worker [INFO]: Deferred: 0 - Total: 0 - Maximum: 1 - jobs per queue: 0 [] []\r\n2019-01-01 20:46:58 worker [INFO]: Path \"/tmp/localhost\" is not writable for user www-data [] []\r\n2019-01-01 20:46:58 worker [INFO]: Load: 0.16/50 - processes: 0/1/0 - maximum: 4/4 [] []\r\n2019-01-01 20:46:58 worker [INFO]: Path \"/tmp/localhost\" is not writable for user www-data [] []\r\n2019-01-01 20:46:58 worker [INFO]: Deferred: 0 - Total: 0 - Maximum: 1 - jobs per queue: 0 [] []\r\n2019-01-01 20:46:58 worker [INFO]: Couldn't select a workerqueue entry, quitting process 3092. [] []\r\n2019-01-01 20:50:01 worker [INFO]: Load: 0.04/50 - processes: 0/1/1 - maximum: 4/4 [] []\r\n2019-01-01 20:50:01 worker [INFO]: Connection usage (system values): 1/151 [] []\r\n2019-01-01 20:50:01 worker [INFO]: Add cron entries [] []\r\n2019-01-01 20:50:01 worker [INFO]: Deferred: 0 - Total: 3 - Maximum: 1 - jobs per queue: 1 [] []\r\n2019-01-01 20:50:01 worker [INFO]: Connection usage (system values): 1/151 [] []\r\n2019-01-01 20:50:01 worker [WARNING]: Process 3151 - Prio 10 - ID 1: DBUpdate [\"DBUpdate\"] - Process PID: wrk:3151:5c2bd2794e9021876 [] []\r\n2019-01-01 20:50:01 worker [INFO]: Update from '1293'  to '1294' - starting [] []\r\n2019-01-01 20:50:01 worker [INFO]: Update function 'pre_update_1294' - start [] []\r\n2019-01-01 20:50:01 worker [INFO]: Skipping 'pre_update_1294' without executing [] []\r\n2019-01-01 20:50:01 worker [INFO]: updating structure [] []\r\n2019-01-01 20:50:01 worker [INFO]: updating structure for table addon ... [] []\r\n2019-01-01 20:54:07 app [NOTICE]: no data for session rouun08qe8g8q4lru2bg519jb4 [] []\r\n2019-01-01 20:54:07 app [NOTICE]: no data for session qcoscuchknvpk556f2tfahbt93 [] []\r\n2019-01-01 20:54:07 app [NOTICE]: no data for session cp2179vo9762pg2qcj1fauluf0 [] []\r\n2019-01-01 20:54:07 app [INFO]: profile error: noscrape/selfcontact [] []\r\n2019-01-01 20:54:07 app [NOTICE]: no data for session j1sb7s50vbnjuhtvlretc46md4 [] []\r\n2019-01-01 20:54:07 app [INFO]: profile error: hcard/selfcontact [] []\r\n2019-01-01 20:54:07 app [NOTICE]: no data for session j3fdlhf1b03t253lmlqgc24ll0 [] []\r\n[...]\r\n```"}}
{"actor":{"display_login":"nupplaphil"}}