{"action":"created","issue":{"url":"https://api.github.com/repos/zatonovo/futile.logger/issues/55","repository_url":"https://api.github.com/repos/zatonovo/futile.logger","labels_url":"https://api.github.com/repos/zatonovo/futile.logger/issues/55/labels{/name}","comments_url":"https://api.github.com/repos/zatonovo/futile.logger/issues/55/comments","events_url":"https://api.github.com/repos/zatonovo/futile.logger/issues/55/events","html_url":"https://github.com/zatonovo/futile.logger/issues/55","id":220739788,"number":55,"title":"Improve performance of skipped log levels","user":{"login":"muxspace","id":581414,"avatar_url":"https://avatars0.githubusercontent.com/u/581414?v=3","gravatar_id":"","url":"https://api.github.com/users/muxspace","html_url":"https://github.com/muxspace","followers_url":"https://api.github.com/users/muxspace/followers","following_url":"https://api.github.com/users/muxspace/following{/other_user}","gists_url":"https://api.github.com/users/muxspace/gists{/gist_id}","starred_url":"https://api.github.com/users/muxspace/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/muxspace/subscriptions","organizations_url":"https://api.github.com/users/muxspace/orgs","repos_url":"https://api.github.com/users/muxspace/repos","events_url":"https://api.github.com/users/muxspace/events{/privacy}","received_events_url":"https://api.github.com/users/muxspace/received_events","type":"User","site_admin":false},"labels":[{"id":275719401,"url":"https://api.github.com/repos/zatonovo/futile.logger/labels/Enhancement","name":"Enhancement","color":"009800","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":2,"created_at":"2017-04-10T19:04:24Z","updated_at":"2017-05-24T18:24:48Z","closed_at":null,"body":"If a log message is below current threshold, exit early and avoid evaluation to improve performance."},"comment":{"url":"https://api.github.com/repos/zatonovo/futile.logger/issues/comments/303810321","html_url":"https://github.com/zatonovo/futile.logger/issues/55#issuecomment-303810321","issue_url":"https://api.github.com/repos/zatonovo/futile.logger/issues/55","id":303810321,"user":{"login":"muxspace","id":581414,"avatar_url":"https://avatars0.githubusercontent.com/u/581414?v=3","gravatar_id":"","url":"https://api.github.com/users/muxspace","html_url":"https://github.com/muxspace","followers_url":"https://api.github.com/users/muxspace/followers","following_url":"https://api.github.com/users/muxspace/following{/other_user}","gists_url":"https://api.github.com/users/muxspace/gists{/gist_id}","starred_url":"https://api.github.com/users/muxspace/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/muxspace/subscriptions","organizations_url":"https://api.github.com/users/muxspace/orgs","repos_url":"https://api.github.com/users/muxspace/repos","events_url":"https://api.github.com/users/muxspace/events{/privacy}","received_events_url":"https://api.github.com/users/muxspace/received_events","type":"User","site_admin":false},"created_at":"2017-05-24T18:24:48Z","updated_at":"2017-05-24T18:24:48Z","body":"@iwccsbfb The actual problem is with `flog.namespace`. See below for performance numbers.\r\n\r\nSetup.\r\n```\r\nlibrary(lambda.tools)\r\nlibrary(futile.logger)\r\nm <- matrix(rnorm(10000), nrow=100)\r\n```\r\nDefault threshold is `INFO`. Printing this message 10000 times takes almost 15 seconds.\r\n```\r\n> system.time(fold(1:10000, function(i,a) { flog.info(\"[%s] sum diag: %s\", i, sum(diag(m)));a }, NULL))\r\n   user  system elapsed \r\n 14.616   0.160  14.783\r\n```\r\nCalling `flog.debug` doesn't print any messages but still takes 3 seconds, so something is eating up resources.\r\n```\r\n> system.time(fold(1:10000, function(i,a) { flog.debug(\"[%s] sum diag: %s\", i, sum(diag(m)));a }, NULL))\r\n   user  system elapsed \r\n  3.364   0.000   3.367\r\n```\r\nUsing `sprintf` results in order of magnitude better performance.\r\n```\r\n> system.time(fold(1:10000, function(i,a) { sprintf(\"[%s] sum diag: %s\", i, sum(diag(m)));a }, NULL))\r\n   user  system elapsed \r\n  0.112   0.000   0.114\r\n```\r\nHere is `flog.namespace` on its own. Note how this is pretty close to the `flog.debug` call at `INFO` threshold.\r\n```\r\n> system.time(fold(1:10000, function(i,a) { flog.namespace(); a }, NULL))   user  system elapsed \r\n  3.052   0.000   3.052 \r\n```"}}
{"actor":{"display_login":"muxspace"}}