renderBoard takes 4 seconds to complete

[allter]

Checklist

• I verified that Kanboard is correctly installed
• I verified that the problem does not come from a plugin
• I verified that the problem is not already reported
• I understand that Kanboard is in maintenance mode. It doesn't mean it's abandoned, but there is no significant feature development

Actual behaviour

When moving cards (even on the same column) it takes a lot of time

Expected behaviour

When moving card it takes a reasonable time

Steps to reproduce (how did i got to there)

I installed kanboard using docker-compose as described in https://docs.kanboard.org/en/latest/admin_guide/docker.html

When my database grew bigger and when i moved it to different pc and updated to the "latest" docker image, many operations began to take a lot of time

First I thought it relates to SQLite performance issues.

I've added more logging and tackled the problem down to renderBoard inside movePosition. But now my knowledge of PHP and its libraries is insufficient.

Logs

I had to add some logging:

[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\Runner::executeMiddleware
[2022-07-11 14:11:08] [debug] Subscriber executed: Kanboard\Subscriber\BootstrapSubscriber::execute
[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\BaseMiddleware::next => Kanboard\Middleware\AuthenticationMiddleware
[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\BaseMiddleware::next => Kanboard\Middleware\PostAuthenticationMiddleware
[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\BaseMiddleware::next => Kanboard\Middleware\ApplicationAuthorizationMiddleware
[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\BaseMiddleware::next => Kanboard\Middleware\ProjectAuthorizationMiddleware
[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\Runner::executeMiddleware-exit
[2022-07-11 14:11:08] [debug] Kanboard\Core\Controller\Runner::executeController => \Kanboard\Controller\BoardAjaxController::save
[2022-07-11 14:11:08] [debug] Kanboard\Controller\BoardAjaxController::save
[2022-07-11 14:11:08] [debug] Kanboard\Controller\BoardAjaxController::save-here
[2022-07-11 14:11:08] [debug] Kanboard\Model\TaskPositionModel::movePosition
[2022-07-11 14:11:08] [debug] Kanboard\Model\TaskPositionModel::movePosition-1
[2022-07-11 14:11:08] [debug] Kanboard\Model\TaskPositionModel::movePosition-2
[2022-07-11 14:11:08] [debug] Kanboard\Job\TaskEventJob::fireEvent Event fired: task.move.position
[2022-07-11 14:11:08] [debug] Subscriber executed: Kanboard\Subscriber\ProjectModificationDateSubscriber::execute
[2022-07-11 14:11:08] [debug] Subscriber executed: Kanboard\Subscriber\NotificationSubscriber::handleEvent
[2022-07-11 14:11:08] [debug] Kanboard\Core\Queue\QueueManager::push: Job executed synchronously: Kanboard\Job\NotificationJob
[2022-07-11 14:11:08] [debug] Kanboard\Model\TaskPositionModel::movePosition-exit
[2022-07-11 14:11:08] [debug] Kanboard\Controller\BoardAjaxController::renderBoard
[2022-07-11 14:11:08] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-2
[2022-07-11 14:11:12] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-exit
[2022-07-11 14:11:12] [debug] Kanboard\Controller\BoardAjaxController::save-exit
[2022-07-11 14:11:12] [debug] Kanboard\Core\Controller\Runner::executeController => \Kanboard\Controller\BoardAjaxController::save-exit

The place when those 4 seconds appear is inside the renderBoard method

    protected function renderBoard($project_id)                                                                                  
    {                                                                                                                            
        if (DEBUG) {                                                                                                             
            $this->logger->debug(__METHOD__);                                                                                    
        }                                                                                                                        
                                                                                                                                 
        $swimlanes =$this->taskLexer                                                                                             
                ->build($this->userSession->getFilters($project_id))                                                             
                ->format($this->boardFormatter->withProjectId($project_id));                                                     
        if (DEBUG) {                                                                                                             
            $this->logger->debug(__METHOD__."-2");                                                                               
        }                                                                                                                        
                                                                                                                                 
        $result = $this->template->render('board/table_container', array(                                                        
            'project' => $this->projectModel->getById($project_id),                                                              
            'board_private_refresh_interval' => $this->configModel->get('board_private_refresh_interval'),
            'board_highlight_period' => $this->configModel->get('board_highlight_period'),                
            'swimlanes' => $swimlanes,                                                                    
        ));                                                                                               
        if (DEBUG) {                                                                                      
            $this->logger->debug(__METHOD__."-exit");                                                     
        }                                                                                                 
        return $result;                                                                                   
    }                                                                                                     

Configuration

    Application version: v1.2.22
    PHP version: 8.0.14
    PHP SAPI: fpm-fcgi
    HTTP Client: cURL
    OS version: Linux 5.13.0-51-generic
    Database driver: sqlite
    Database version: 3.36.0
    Browser: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0

[allter]

Any ideas where to look for more info/how to fix?

[allter]

P.S I've added another log message and found that it's the following method which is slow

$this->template->render(

    protected function renderBoard($project_id)                                                                                  
    {                                                                                                                            
        if (DEBUG) {                                                                                                             
            $this->logger->debug(__METHOD__);                                                                                    
        }                                                                                                                        
                                                                                                                                 
        $swimlanes =$this->taskLexer                                                                                             
                ->build($this->userSession->getFilters($project_id))                                                             
                ->format($this->boardFormatter->withProjectId($project_id));                                                     
        if (DEBUG) {                                                                                                             
            $this->logger->debug(__METHOD__."-2");                                                                               
        }                                                                                                                        
        $params = array(                                                                                                         
            'project' => $this->projectModel->getById($project_id),                                                              
            'board_private_refresh_interval' => $this->configModel->get('board_private_refresh_interval'),                       
            'board_highlight_period' => $this->configModel->get('board_highlight_period'),                                       
            'swimlanes' => $swimlanes,                                                                                           
        );                                                                                                                       
        if (DEBUG) {                                                                                                             
            $this->logger->debug(__METHOD__."-3");                                                        
        }                                                                                                 
                                                                                                          
                                                                                                          
        $result = $this->template->render('board/table_container', $params);                              
        if (DEBUG) {                                                                                      
            $this->logger->debug(__METHOD__."-exit");                                                     
        }                                                                                                 
        return $result;                                                                                   
}

[2022-07-11 15:36:50] [debug] Kanboard\Controller\BoardAjaxController::renderBoard
[2022-07-11 15:36:50] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-2
[2022-07-11 15:36:50] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-3
[2022-07-11 15:36:55] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-exit

Looks like the issue is related to the issue described here: https://kanboard.discourse.group/t/some-of-the-biggest-performance-issues-are-in-the-board-view-not-the-sqlite-database-backend/762

[allter]

Strange thing. I restarted kanboard docker container and now I can't reproduce the following although this log is actual log.

[2022-07-11 15:36:50] [debug] Kanboard\Controller\BoardAjaxController::renderBoard
[2022-07-11 15:36:50] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-2
[2022-07-11 15:36:50] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-3
[2022-07-11 15:36:55] [debug] Kanboard\Controller\BoardAjaxController::renderBoard-exit

Still moving cards on my board is slow because of JS performance problem, which is a separate issue.

[Chaosmeister]

how many tasks are in your board?
sqlite has the habit of reducing performance with every added task.
you could clean up your database, delete old tasks or switch to another database.

[allter]

About 150-200 tasks on my board.

I've investigated and it seems like the slowness is because of another issue with UI: #5113

I could not reproduce the current bug anymore. Maybe there were several boards open and interacting with the backend (concurrency issues with SQLite).

[Chaosmeister]

kanboard and sqlite is not that good with concurrent or multiuser instances.
we also switched as soon as we noticed a performance degradation and haven't seen any database related performance issues since then.

[fguillot]

Let's merge this issue with #4389 which is also about performance degradation.