[Mon Mar 27 13:09:29.388176 2023]  Backend log: [debug] Kanboard\\Core\\Controller\\Runner::executeMiddleware\n
[Mon Mar 27 13:09:29.392070 2023]  Backend log: [debug] Subscriber executed: Kanboard\\Subscriber\\BootstrapSubscriber::execute\n
[Mon Mar 27 13:09:29.397086 2023]  Backend log: [debug] Kanboard\\Core\\Controller\\BaseMiddleware::next => Kanboard\\Middleware\\AuthenticationMiddleware\n
[Mon Mar 27 13:09:29.398278 2023]  Backend log: [debug] Kanboard\\Core\\Controller\\Runner::executeController => \\Kanboard\\Plugin\\OAuth2\\Controller\\OAuthController::handler\n
[Mon Mar 27 13:09:29.399597 2023]  Backend log: [debug] HttpClient::doRequest: cURL detected\n
[Mon Mar 27 13:09:29.588723 2023]  Backend log: [debug] HttpClient: url=https://auth.REDACTEDDOMAIN/application/o/token/\n
[Mon Mar 27 13:09:29.588780 2023]  Backend log: [debug] HttpClient: headers=array (\n  0 => 'Content-type: application/x-www-form-urlencoded',\n  1 => 'Accept: application/json',\n)\n
[Mon Mar 27 13:09:29.588798 2023]  Backend log: [debug] HttpClient: payload=code=6183af480a2d4db495b7c3d8b8a686e3&client_id=d715040f9eaeea053d97a22687244fef6c91977d&client_secret=9f0fee09beb813d2ce438425edb299bac8ed2f687fd5c8afe196e59b09a04575ee797885f0c2783d3fcdbdbaf07e16ef069cb83333f208b75ba2aa2eed736326&redirect_uri=https%3A%2F%2Fplan.REDACTEDDOMAIN%2F%3Fcontroller%3DOAuthController%26action%3Dhandler%26plugin%3DOAuth2&grant_type=authorization_code&state=26f41e108ea08e9355a5049aa3d75b3f795ba4a233f60957859b2b5394e0\n
[Mon Mar 27 13:09:29.588832 2023]  Backend log: [debug] HttpClient: metadata=array (\n  'url' => 'https://auth.REDACTEDDOMAIN/application/o/token/',\n  'content_type' => 'application/json',\n  'http_code' => 200,\n  'header_size' => 397,\n  'request_size' => 636,\n  'filetime' => -1,\n  'ssl_verify_result' => 0,\n  'redirect_count' => 0,\n  'total_time' => 0.187019,\n  'namelookup_time' => 0.001703,\n  'connect_time' => 0.00245,\n  'pretransfer_time' => 0.017481,\n  'size_upload' => 449.0,\n  'size_download' => 1346.0,\n  'speed_download' => 7197.0,\n  'speed_upload' => 2400.0,\n  'download_content_length' => 1346.0,\n  'upload_content_length' => 449.0,\n  'starttransfer_time' => 0.18694,\n  'redirect_time' => 0.0,\n  'redirect_url' => '',\n  'primary_ip' => '207.90.251.22',\n  'certinfo' => \n  array (\n  ),\n  'primary_port' => 443,\n  'local_ip' => '207.90.251.10',\n  'local_port' => 37106,\n  'http_version' => 2,\n  'protocol' => 2,\n  'ssl_verifyresult' => 0,\n  'scheme' => 'HTTPS',\n  'appconnect_time_us' => 17416,\n  'connect_time_us' => 2450,\n  'namelookup_time_us' => 1703,\n  'pretransfer_time_us' => 17481,\n  'redirect_time_us' => 0,\n  'starttransfer_time_us' => 186940,\n  'total_time_us' => 187019,\n)\n
[Mon Mar 27 13:09:29.588877 2023]  Backend log: [debug] HttpClient: body={"access_token": "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJodHRwczovL2F1dGgudGhlZW5kbGVzc3dlYi5jb20vYXBwbGljYXRpb24vby9rYW5ib2FyZC8iLCJzdWIiOiJkMTU0MGQ0NzlmNDUxMzI2YTk2MWQ3ZTFhNWM5ZmM0OTdhOGNhYTBjYjkwYTYxNDA1MmJhNmIwMjZlNzg0OGNjIiwiYXVkIjoiZDcxNTA0MGY5ZWFlZWEwNTNkOTdhMjI2ODcyNDRmZWY2YzkxOTc3ZCIsImV4cCI6MTY3OTkzNzI2OSwiaWF0IjoxNjc5OTM2OTY5LCJhdXRoX3RpbWUiOjE2Nzk5MzEwOTYsImFjciI6ImdvYXV0aGVudGlrLmlvL3Byb3ZpZGVycy9vYXV0aDIvZGVmYXVsdCIsImF6cCI6ImQ3MTUwNDBmOWVhZWVhMDUzZDk3YTIyNjg3MjQ0ZmVmNmM5MTk3N2QiLCJ1aWQiOiJ0MU5HTDN5ckZnbUszeWxnZkJMemxCenpMenNzaGxKV2pCOHM5TGJzIn0.1nOBdcSofKi8s2KlvMN3-588tCj-PiZiL_Y9PNflltY", "refresh_token": "$(kh1kSl$L8yKyHZXw``OG)REw)#d;TJD4~xlvE=:kd,kG)Bc=,1NteNp7?GhiU[,{MrK;+1?Ea8qD,KLn<[i~.;DUEH$:]Ng`}{P\\"N8+\\"H}Cq:$r!lY36&Mu'?h4!^'", "token_type": "Bearer", "expires_in": 300, "id_token": "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJodHRwczovL2F1dGgudGhlZW5kbGVzc3dlYi5jb20vYXBwbGljYXRpb24vby9rYW5ib2FyZC8iLCJzdWIiOiJkMTU0MGQ0NzlmNDUxMzI2YTk2MWQ3ZTFhNWM5ZmM0OTdhOGNhYTBjYjkwYTYxNDA1MmJhNmIwMjZlNzg0OGNjIiwiYXVkIjoiZDcxNTA0MGY5ZWFlZWEwNTNkOTdhMjI2ODcyNDRmZWY2YzkxOTc3ZCIsImV4cCI6MTY4MjUyODk2OSwiaWF0IjoxNjc5OTM2OTY5LCJhdXRoX3RpbWUiOjE2Nzk5MzEwOTYsImFjciI6ImdvYXV0aGVudGlrLmlvL3Byb3ZpZGVycy9vYXV0aDIvZGVmYXVsdCIsImF0X2hhc2giOiJFWTVFV1dFWElHSkg3V3ZKM2RHNWh3In0.OO-FnJtsoXT-5s35gzW9Ml-ihgB2nhhh9d8rn09li10"}\n
[Mon Mar 27 13:09:29.588905 2023]  Backend log: [debug] HttpClient: executionTime=0.18866419792175\n
[Mon Mar 27 13:09:29.588920 2023]  Backend log: [debug] Kanboard\\Plugin\\OAuth2\\Auth\\GenericOAuth2Provider::getProfile: Got access token: Yes\n
[Mon Mar 27 13:09:29.588934 2023]  Backend log: [debug] Kanboard\\Plugin\\OAuth2\\Auth\\GenericOAuth2Provider::getProfile: Fetch user profile from https://auth.REDACTEDDOMAIN/application/o/userinfo/\n
[Mon Mar 27 13:09:29.588949 2023]  Backend log: [debug] HttpClient::doRequest: cURL detected\n
[Mon Mar 27 13:09:29.634110 2023]  Backend log: [debug] HttpClient: url=https://auth.REDACTEDDOMAIN/application/o/userinfo/\n
[Mon Mar 27 13:09:29.634185 2023]  Backend log: [debug] HttpClient: headers=array (\n  0 => 'Accept: application/json',\n  1 => 'Authorization: Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJodHRwczovL2F1dGgudGhlZW5kbGVzc3dlYi5jb20vYXBwbGljYXRpb24vby9rYW5ib2FyZC8iLCJzdWIiOiJkMTU0MGQ0NzlmNDUxMzI2YTk2MWQ3ZTFhNWM5ZmM0OTdhOGNhYTBjYjkwYTYxNDA1MmJhNmIwMjZlNzg0OGNjIiwiYXVkIjoiZDcxNTA0MGY5ZWFlZWEwNTNkOTdhMjI2ODcyNDRmZWY2YzkxOTc3ZCIsImV4cCI6MTY3OTkzNzI2OSwiaWF0IjoxNjc5OTM2OTY5LCJhdXRoX3RpbWUiOjE2Nzk5MzEwOTYsImFjciI6ImdvYXV0aGVudGlrLmlvL3Byb3ZpZGVycy9vYXV0aDIvZGVmYXVsdCIsImF6cCI6ImQ3MTUwNDBmOWVhZWVhMDUzZDk3YTIyNjg3MjQ0ZmVmNmM5MTk3N2QiLCJ1aWQiOiJ0MU5HTDN5ckZnbUszeWxnZkJMemxCenpMenNzaGxKV2pCOHM5TGJzIn0.1nOBdcSofKi8s2KlvMN3-588tCj-PiZiL_Y9PNflltY',\n)\n
[Mon Mar 27 13:09:29.634223 2023]  Backend log: [debug] HttpClient: payload=\n
[Mon Mar 27 13:09:29.634240 2023]  Backend log: [debug] HttpClient: metadata=array (\n  'url' => 'https://auth.REDACTEDDOMAIN/application/o/userinfo/',\n  'content_type' => 'text/html; charset=utf-8',\n  'http_code' => 403,\n  'header_size' => 506,\n  'request_size' => 743,\n  'filetime' => -1,\n  'ssl_verify_result' => 0,\n  'redirect_count' => 0,\n  'total_time' => 0.040061,\n  'namelookup_time' => 0.001052,\n  'connect_time' => 0.001724,\n  'pretransfer_time' => 0.014768,\n  'size_upload' => 0.0,\n  'size_download' => 0.0,\n  'speed_download' => 0.0,\n  'speed_upload' => 0.0,\n  'download_content_length' => 0.0,\n  'upload_content_length' => 0.0,\n  'starttransfer_time' => 0.040014,\n  'redirect_time' => 0.0,\n  'redirect_url' => '',\n  'primary_ip' => '207.90.251.22',\n  'certinfo' => \n  array (\n  ),\n  'primary_port' => 443,\n  'local_ip' => '207.90.251.10',\n  'local_port' => 37108,\n  'http_version' => 2,\n  'protocol' => 2,\n  'ssl_verifyresult' => 0,\n  'scheme' => 'HTTPS',\n  'appconnect_time_us' => 14702,\n  'connect_time_us' => 1724,\n  'namelookup_time_us' => 1052,\n  'pretransfer_time_us' => 14768,\n  'redirect_time_us' => 0,\n  'starttransfer_time_us' => 40014,\n  'total_time_us' => 40061,\n)\n
[Mon Mar 27 13:09:29.634284 2023]  Backend log: [debug] HttpClient: body=\n
[Mon Mar 27 13:09:29.634301 2023]  Backend log: [debug] HttpClient: executionTime=0.041558980941772\n
[Mon Mar 27 13:09:29.634316 2023]  Backend log: [debug] Subscriber executed: Kanboard\\Subscriber\\AuthSubscriber::onLoginFailure\n
[Mon Mar 27 13:09:29.634343 2023]  Backend log: Kanboard: user Unknown authentication failure with IP address: 149.19.54.73\n
[Mon Mar 27 13:09:30.388579 2023]  Backend log: [debug] SQL: SELECT  `plugin_schema_versions`.`version` FROM `plugin_schema_versions`   WHERE `plugin` = ?    LIMIT 1\n
[Mon Mar 27 13:09:30.388635 2023]  Backend log: [debug] SQL: param[1]: 'oauth2'\n
[Mon Mar 27 13:09:30.388652 2023]  Backend log: [debug] SQL: query_duration=0.00066304206848145\n
[Mon Mar 27 13:09:30.388667 2023]  Backend log: [debug] SQL: total_execution_time=0.00066304206848145\n
[Mon Mar 27 13:09:30.388682 2023]  Backend log: [debug] SQL: SELECT  `sessions`.`data` FROM `sessions`   WHERE `id` = ?    LIMIT 1\n
[Mon Mar 27 13:09:30.388705 2023]  Backend log: [debug] SQL: param[1]: 'a9731f2796142ac9a42f9bca30e1e782'\n
[Mon Mar 27 13:09:30.388720 2023]  Backend log: [debug] SQL: query_duration=0.00055384635925293\n
[Mon Mar 27 13:09:30.388735 2023]  Backend log: [debug] SQL: total_execution_time=0.0012168884277344\n
[Mon Mar 27 13:09:30.388748 2023]  Backend log: [debug] SQL: SELECT  `settings`.`option`, `settings`.`value` FROM `settings`\n
[Mon Mar 27 13:09:30.388762 2023]  Backend log: [debug] SQL: query_duration=0.00040388107299805\n
[Mon Mar 27 13:09:30.388776 2023]  Backend log: [debug] SQL: total_execution_time=0.0016207695007324\n
[Mon Mar 27 13:09:30.388790 2023]  Backend log: [debug] SQL: SELECT  * FROM `actions`\n
[Mon Mar 27 13:09:30.388803 2023]  Backend log: [debug] SQL: query_duration=0.00039100646972656\n
[Mon Mar 27 13:09:30.388817 2023]  Backend log: [debug] SQL: total_execution_time=0.002011775970459\n
[Mon Mar 27 13:09:30.388831 2023]  Backend log: [debug] SQL: SELECT  * FROM `action_has_params`\n
[Mon Mar 27 13:09:30.388845 2023]  Backend log: [debug] SQL: query_duration=0.00033807754516602\n
[Mon Mar 27 13:09:30.388859 2023]  Backend log: [debug] SQL: total_execution_time=0.002349853515625\n
[Mon Mar 27 13:09:30.388873 2023]  Backend log: [debug] SQL: SELECT 1 FROM `sessions`  WHERE `id` = ?\n
[Mon Mar 27 13:09:30.388887 2023]  Backend log: [debug] SQL: param[1]: 'a9731f2796142ac9a42f9bca30e1e782'\n
[Mon Mar 27 13:09:30.388901 2023]  Backend log: [debug] SQL: query_duration=0.00069308280944824\n
[Mon Mar 27 13:09:30.388914 2023]  Backend log: [debug] SQL: total_execution_time=0.0030429363250732\n
[Mon Mar 27 13:09:30.388928 2023]  Backend log: [debug] SQL: UPDATE `sessions` SET `expire_at`=?, `data`=?  WHERE `id` = ?\n
[Mon Mar 27 13:09:30.388942 2023]  Backend log: [debug] SQL: param[1]: '1679938409'\n
[Mon Mar 27 13:09:30.388956 2023]  Backend log: [debug] SQL: param[2]: 'csrf_key|s:64:"44902262927caee25e3040947221013d739de0d88cbda362063abc2e79f1671d";oauthState|s:60:"26f41e108ea08e9355a5049aa3d75b3f795ba4a233f60957859b2b5394e0";'\n
[Mon Mar 27 13:09:30.388977 2023]  Backend log: [debug] SQL: param[3]: 'a9731f2796142ac9a42f9bca30e1e782'\n
[Mon Mar 27 13:09:30.388992 2023]  Backend log: [debug] SQL: query_duration=0.00050115585327148\n
[Mon Mar 27 13:09:30.389007 2023]  Backend log: [debug] SQL: total_execution_time=0.0035440921783447\n
[Mon Mar 27 13:09:30.389042 2023]  Backend log: [debug] APP: nb_queries=7\n
[Mon Mar 27 13:09:30.389067 2023]  Backend log: [debug] APP: rendering_time=1.1068949699402\n
[Mon Mar 27 13:09:30.389082 2023]  Backend log: [debug] APP: memory_usage=5.81M\n
[Mon Mar 27 13:09:30.389105 2023]  Backend log: [debug] APP: uri=/?controller=OAuthController&action=handler&plugin=OAuth2&code=6183af480a2d4db495b7c3d8b8a686e3&state=26f41e108ea08e9355a5049aa3d75b3f795ba4a233f60957859b2b5394e0\n
[Mon Mar 27 13:09:30.389122 2023]  Backend log: [debug] ###############################################\n