Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Deadlock found when trying to get lock #4093

Closed
solracsf opened this issue Sep 3, 2020 · 23 comments
Closed

Deadlock found when trying to get lock #4093

solracsf opened this issue Sep 3, 2020 · 23 comments
Labels
0. Needs triage bug feature: api 🛠️ OCS API for conversations, chats and participants
Milestone

Comments

@solracsf
Copy link
Member

solracsf commented Sep 3, 2020

Actual behaviour

Messages on the Talk app like "Message not found" or "Double session, you are already connected on another device"

Is this related to nextcloud/server#22482 ?

Talk app

Talk app version:
9.0.3

Custom Signaling server configured:
No

Custom TURN server configured:
Yes

Custom STUN server configured:
Yes

Browser

Chrome or Firefox, same behavior

Browser log

Error: Request aborted
    exports createError.js:16
    onabort xhr.js:73
    exports xhr.js:68
    exports xhr.js:12
    exports dispatchRequest.js:52
    promise callback*c.prototype.request Axios.js:61
    e Axios.js:76
    exports bind.js:9
    e participantsService.js:226
    c runtime.js:45
    _invoke runtime.js:274
    t runtime.js:97
    p talk.js:388
    o talk.js:388
    f talk.js:388
    f talk.js:388
    S participantsService.js:225
    n cancelableRequest.js:49
    c runtime.js:45
    _invoke runtime.js:274
    t runtime.js:97
    i talk.js:559
    s talk.js:559
    r talk.js:559
    r talk.js:559
    request cancelableRequest.js:48
    n ParticipantsTab.vue:229
    c runtime.js:45
    _invoke runtime.js:274
    t runtime.js:97
    Cr talk.js:1916
    o talk.js:1916
    Sr talk.js:1916
    Sr talk.js:1916
    cancelableGetParticipants ParticipantsTab.vue:214
ParticipantsTab.vue:248
Please do NOT wait for the DOMContentLoaded before registering your viewer handler Viewer.vue:210
    handlers Viewer.vue:210
    VueJS 10
    value Viewer.js:73
    initPage viewer.js:109
    onSuccess viewer.js:51
    jQuery 7
    GetSettings viewer.js:47
    initPage viewer.js:103
    jQuery 7
    Webpack 6

Server configuration

Operating system: Ubuntu/RedHat/...
Ubuntu

Web server: Apache/Nginx
Nginx 1.19.2

Database: MySQL/Maria/SQLite/PostgreSQL
MariaDB 10.4.14

PHP version: 7.2/7.3/7.4
7.3.21

Nextcloud Version: (see admin page)
19.0.2

Server log (data/nextcloud.log)

{
  "reqId":"zXft72xmnmfofFywqNK2",
  "level":3,
  "time":"2020-09-03T10:15:10+02:00",
  "remoteAddr":"81.64.253.167",
  "user":"bruno",
  "app":"no app in context",
  "method":"GET",
  "url":"/ocs/v2.php/apps/spreed/api/v1/signaling/sdryevb8",
  "message":{
    "Exception":"Doctrine\\DBAL\\Exception\\DeadlockException",
    "Message":"An exception occurred while executing 'UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)' with params [1599120910, \"b.guillaumie\", \"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p\", 35]:\n\nSQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction",
    "Code":0,
    "Trace":[
      {
        "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DBALException.php",
        "line":169,
        "function":"convertException",
        "class":"Doctrine\\DBAL\\Driver\\AbstractMySQLDriver",
        "type":"->",
        "args":[
          "An exception occurred while executing 'UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)' with params [1599120910, \"b.guillaumie\", \"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p\", 35]:\n\nSQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction",
          {
            "errorInfo":[
              "40001",
              1213,
              "Deadlock found when trying to get lock; try restarting transaction"
            ],
            "__class__":"Doctrine\\DBAL\\Driver\\PDOException"
          }
        ]
      },
      {
        "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DBALException.php",
        "line":145,
        "function":"wrapException",
        "class":"Doctrine\\DBAL\\DBALException",
        "type":"::",
        "args":[
          {
            "__class__":"Doctrine\\DBAL\\Driver\\PDOMySql\\Driver"
          },
          {
            "errorInfo":[
              "40001",
              1213,
              "Deadlock found when trying to get lock; try restarting transaction"
            ],
            "__class__":"Doctrine\\DBAL\\Driver\\PDOException"
          },
          "An exception occurred while executing 'UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)' with params [1599120910, \"b.guillaumie\", \"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p\", 35]:\n\nSQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction"
        ]
      },
      {
        "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php",
        "line":1063,
        "function":"driverExceptionDuringQuery",
        "class":"Doctrine\\DBAL\\DBALException",
        "type":"::",
        "args":[
          {
            "__class__":"Doctrine\\DBAL\\Driver\\PDOMySql\\Driver"
          },
          {
            "errorInfo":[
              "40001",
              1213,
              "Deadlock found when trying to get lock; try restarting transaction"
            ],
            "__class__":"Doctrine\\DBAL\\Driver\\PDOException"
          },
          "UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)",
          {
            "1":1599120910,
            "2":"b.guillaumie",
            "3":"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
            "4":35
          }
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/DB/Connection.php",
        "line":214,
        "function":"executeUpdate",
        "class":"Doctrine\\DBAL\\Connection",
        "type":"->",
        "args":[
          "UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)",
          [
            1599120910,
            "b.guillaumie",
            "oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
            35
          ],
          [
            1,
            2,
            2,
            1
          ]
        ]
      },
      {
        "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php",
        "line":203,
        "function":"executeUpdate",
        "class":"OC\\DB\\Connection",
        "type":"->",
        "args":[
          "UPDATE `oc_talk_participants` SET `last_ping` = :dcValue1 WHERE (`user_id` = :dcValue2) AND (`session_id` = :dcValue3) AND (`room_id` = :dcValue4)",
          {
            "dcValue1":1599120910,
            "dcValue2":"b.guillaumie",
            "dcValue3":"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
            "dcValue4":35
          },
          {
            "dcValue1":1,
            "dcValue2":2,
            "dcValue3":2,
            "dcValue4":1
          }
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/DB/QueryBuilder/QueryBuilder.php",
        "line":216,
        "function":"execute",
        "class":"Doctrine\\DBAL\\Query\\QueryBuilder",
        "type":"->",
        "args":[
          
        ]
      },
      {
        "file":"/var/www/nextcloud/apps/spreed/lib/Room.php",
        "line":1323,
        "function":"execute",
        "class":"OC\\DB\\QueryBuilder\\QueryBuilder",
        "type":"->",
        "args":[
          
        ]
      },
      {
        "file":"/var/www/nextcloud/apps/spreed/lib/Controller/SignalingController.php",
        "line":276,
        "function":"ping",
        "class":"OCA\\Talk\\Room",
        "type":"->",
        "args":[
          "b.guillaumie",
          "oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
          1599120910
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
        "line":170,
        "function":"pullMessages",
        "class":"OCA\\Talk\\Controller\\SignalingController",
        "type":"->",
        "args":[
          "sdryevb8"
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
        "line":100,
        "function":"executeController",
        "class":"OC\\AppFramework\\Http\\Dispatcher",
        "type":"->",
        "args":[
          {
            "__class__":"OCA\\Talk\\Controller\\SignalingController"
          },
          "pullMessages"
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/AppFramework/App.php",
        "line":137,
        "function":"dispatch",
        "class":"OC\\AppFramework\\Http\\Dispatcher",
        "type":"->",
        "args":[
          {
            "__class__":"OCA\\Talk\\Controller\\SignalingController"
          },
          "pullMessages"
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/AppFramework/Routing/RouteActionHandler.php",
        "line":47,
        "function":"main",
        "class":"OC\\AppFramework\\App",
        "type":"::",
        "args":[
          "OCA\\Talk\\Controller\\SignalingController",
          "pullMessages",
          {
            "__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"
          },
          {
            "apiVersion":"v1",
            "token":"sdryevb8",
            "_route":"ocs.spreed.Signaling.pullMessages"
          }
        ]
      },
      {
        "function":"__invoke",
        "class":"OC\\AppFramework\\Routing\\RouteActionHandler",
        "type":"->",
        "args":[
          {
            "apiVersion":"v1",
            "token":"sdryevb8",
            "_route":"ocs.spreed.Signaling.pullMessages"
          }
        ]
      },
      {
        "file":"/var/www/nextcloud/lib/private/Route/Router.php",
        "line":297,
        "function":"call_user_func",
        "args":[
          {
            "__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"
          },
          {
            "apiVersion":"v1",
            "token":"sdryevb8",
            "_route":"ocs.spreed.Signaling.pullMessages"
          }
        ]
      },
      {
        "file":"/var/www/nextcloud/ocs/v1.php",
        "line":88,
        "function":"match",
        "class":"OC\\Route\\Router",
        "type":"->",
        "args":[
          "/ocsapp/apps/spreed/api/v1/signaling/sdryevb8"
        ]
      },
      {
        "file":"/var/www/nextcloud/ocs/v2.php",
        "line":24,
        "args":[
          "/var/www/nextcloud/ocs/v1.php"
        ],
        "function":"require_once"
      }
    ],
    "File":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/AbstractMySQLDriver.php",
    "Line":34,
    "Previous":{
      "Exception":"Doctrine\\DBAL\\Driver\\PDOException",
      "Message":"SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction",
      "Code":"40001",
      "Trace":[
        {
          "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php",
          "line":1054,
          "function":"execute",
          "class":"Doctrine\\DBAL\\Driver\\PDOStatement",
          "type":"->",
          "args":[
            
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/DB/Connection.php",
          "line":214,
          "function":"executeUpdate",
          "class":"Doctrine\\DBAL\\Connection",
          "type":"->",
          "args":[
            "UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)",
            [
              1599120910,
              "b.guillaumie",
              "oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
              35
            ],
            [
              1,
              2,
              2,
              1
            ]
          ]
        },
        {
          "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php",
          "line":203,
          "function":"executeUpdate",
          "class":"OC\\DB\\Connection",
          "type":"->",
          "args":[
            "UPDATE `oc_talk_participants` SET `last_ping` = :dcValue1 WHERE (`user_id` = :dcValue2) AND (`session_id` = :dcValue3) AND (`room_id` = :dcValue4)",
            {
              "dcValue1":1599120910,
              "dcValue2":"b.guillaumie",
              "dcValue3":"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
              "dcValue4":35
            },
            {
              "dcValue1":1,
              "dcValue2":2,
              "dcValue3":2,
              "dcValue4":1
            }
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/DB/QueryBuilder/QueryBuilder.php",
          "line":216,
          "function":"execute",
          "class":"Doctrine\\DBAL\\Query\\QueryBuilder",
          "type":"->",
          "args":[
            
          ]
        },
        {
          "file":"/var/www/nextcloud/apps/spreed/lib/Room.php",
          "line":1323,
          "function":"execute",
          "class":"OC\\DB\\QueryBuilder\\QueryBuilder",
          "type":"->",
          "args":[
            
          ]
        },
        {
          "file":"/var/www/nextcloud/apps/spreed/lib/Controller/SignalingController.php",
          "line":276,
          "function":"ping",
          "class":"OCA\\Talk\\Room",
          "type":"->",
          "args":[
            "b.guillaumie",
            "oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
            1599120910
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
          "line":170,
          "function":"pullMessages",
          "class":"OCA\\Talk\\Controller\\SignalingController",
          "type":"->",
          "args":[
            "sdryevb8"
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
          "line":100,
          "function":"executeController",
          "class":"OC\\AppFramework\\Http\\Dispatcher",
          "type":"->",
          "args":[
            {
              "__class__":"OCA\\Talk\\Controller\\SignalingController"
            },
            "pullMessages"
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/AppFramework/App.php",
          "line":137,
          "function":"dispatch",
          "class":"OC\\AppFramework\\Http\\Dispatcher",
          "type":"->",
          "args":[
            {
              "__class__":"OCA\\Talk\\Controller\\SignalingController"
            },
            "pullMessages"
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/AppFramework/Routing/RouteActionHandler.php",
          "line":47,
          "function":"main",
          "class":"OC\\AppFramework\\App",
          "type":"::",
          "args":[
            "OCA\\Talk\\Controller\\SignalingController",
            "pullMessages",
            {
              "__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"
            },
            {
              "apiVersion":"v1",
              "token":"sdryevb8",
              "_route":"ocs.spreed.Signaling.pullMessages"
            }
          ]
        },
        {
          "function":"__invoke",
          "class":"OC\\AppFramework\\Routing\\RouteActionHandler",
          "type":"->",
          "args":[
            {
              "apiVersion":"v1",
              "token":"sdryevb8",
              "_route":"ocs.spreed.Signaling.pullMessages"
            }
          ]
        },
        {
          "file":"/var/www/nextcloud/lib/private/Route/Router.php",
          "line":297,
          "function":"call_user_func",
          "args":[
            {
              "__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"
            },
            {
              "apiVersion":"v1",
              "token":"sdryevb8",
              "_route":"ocs.spreed.Signaling.pullMessages"
            }
          ]
        },
        {
          "file":"/var/www/nextcloud/ocs/v1.php",
          "line":88,
          "function":"match",
          "class":"OC\\Route\\Router",
          "type":"->",
          "args":[
            "/ocsapp/apps/spreed/api/v1/signaling/sdryevb8"
          ]
        },
        {
          "file":"/var/www/nextcloud/ocs/v2.php",
          "line":24,
          "args":[
            "/var/www/nextcloud/ocs/v1.php"
          ],
          "function":"require_once"
        }
      ],
      "File":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php",
      "Line":119,
      "Previous":{
        "Exception":"PDOException",
        "Message":"SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction",
        "Code":"40001",
        "Trace":[
          {
            "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php",
            "line":117,
            "function":"execute",
            "class":"PDOStatement",
            "type":"->",
            "args":[
              null
            ]
          },
          {
            "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php",
            "line":1054,
            "function":"execute",
            "class":"Doctrine\\DBAL\\Driver\\PDOStatement",
            "type":"->",
            "args":[
              
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/DB/Connection.php",
            "line":214,
            "function":"executeUpdate",
            "class":"Doctrine\\DBAL\\Connection",
            "type":"->",
            "args":[
              "UPDATE `oc_talk_participants` SET `last_ping` = ? WHERE (`user_id` = ?) AND (`session_id` = ?) AND (`room_id` = ?)",
              [
                1599120910,
                "b.guillaumie",
                "oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
                35
              ],
              [
                1,
                2,
                2,
                1
              ]
            ]
          },
          {
            "file":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php",
            "line":203,
            "function":"executeUpdate",
            "class":"OC\\DB\\Connection",
            "type":"->",
            "args":[
              "UPDATE `oc_talk_participants` SET `last_ping` = :dcValue1 WHERE (`user_id` = :dcValue2) AND (`session_id` = :dcValue3) AND (`room_id` = :dcValue4)",
              {
                "dcValue1":1599120910,
                "dcValue2":"b.guillaumie",
                "dcValue3":"oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
                "dcValue4":35
              },
              {
                "dcValue1":1,
                "dcValue2":2,
                "dcValue3":2,
                "dcValue4":1
              }
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/DB/QueryBuilder/QueryBuilder.php",
            "line":216,
            "function":"execute",
            "class":"Doctrine\\DBAL\\Query\\QueryBuilder",
            "type":"->",
            "args":[
              
            ]
          },
          {
            "file":"/var/www/nextcloud/apps/spreed/lib/Room.php",
            "line":1323,
            "function":"execute",
            "class":"OC\\DB\\QueryBuilder\\QueryBuilder",
            "type":"->",
            "args":[
              
            ]
          },
          {
            "file":"/var/www/nextcloud/apps/spreed/lib/Controller/SignalingController.php",
            "line":276,
            "function":"ping",
            "class":"OCA\\Talk\\Room",
            "type":"->",
            "args":[
              "b.guillaumie",
              "oumohMytuE3ealXquFb6N1sgf99GHLo4ZbwoTXFF6DBfzUcOdZBsnOqT66uO+VOoCNXgReHeVGrV6ZbR9Cyz0celLsEsH71YJy+xTrgdQHYcoz4+2t+2Jl6RrioUG2H9NFd63q7lJdUzTKaeNrSeVfyZW2mkC7uPVANMqIuN3tBCxOfKZXAsC3+IgX5+5sYGUVrfHLH8qlZYeM+4aQK89LBO8uOxvf1OwBFMi14TNE2521YF0b5TjNsX7jQOc1p",
              1599120910
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
            "line":170,
            "function":"pullMessages",
            "class":"OCA\\Talk\\Controller\\SignalingController",
            "type":"->",
            "args":[
              "sdryevb8"
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php",
            "line":100,
            "function":"executeController",
            "class":"OC\\AppFramework\\Http\\Dispatcher",
            "type":"->",
            "args":[
              {
                "__class__":"OCA\\Talk\\Controller\\SignalingController"
              },
              "pullMessages"
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/AppFramework/App.php",
            "line":137,
            "function":"dispatch",
            "class":"OC\\AppFramework\\Http\\Dispatcher",
            "type":"->",
            "args":[
              {
                "__class__":"OCA\\Talk\\Controller\\SignalingController"
              },
              "pullMessages"
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/AppFramework/Routing/RouteActionHandler.php",
            "line":47,
            "function":"main",
            "class":"OC\\AppFramework\\App",
            "type":"::",
            "args":[
              "OCA\\Talk\\Controller\\SignalingController",
              "pullMessages",
              {
                "__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"
              },
              {
                "apiVersion":"v1",
                "token":"sdryevb8",
                "_route":"ocs.spreed.Signaling.pullMessages"
              }
            ]
          },
          {
            "function":"__invoke",
            "class":"OC\\AppFramework\\Routing\\RouteActionHandler",
            "type":"->",
            "args":[
              {
                "apiVersion":"v1",
                "token":"sdryevb8",
                "_route":"ocs.spreed.Signaling.pullMessages"
              }
            ]
          },
          {
            "file":"/var/www/nextcloud/lib/private/Route/Router.php",
            "line":297,
            "function":"call_user_func",
            "args":[
              {
                "__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"
              },
              {
                "apiVersion":"v1",
                "token":"sdryevb8",
                "_route":"ocs.spreed.Signaling.pullMessages"
              }
            ]
          },
          {
            "file":"/var/www/nextcloud/ocs/v1.php",
            "line":88,
            "function":"match",
            "class":"OC\\Route\\Router",
            "type":"->",
            "args":[
              "/ocsapp/apps/spreed/api/v1/signaling/sdryevb8"
            ]
          },
          {
            "file":"/var/www/nextcloud/ocs/v2.php",
            "line":24,
            "args":[
              "/var/www/nextcloud/ocs/v1.php"
            ],
            "function":"require_once"
          }
        ],
        "File":"/var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php",
        "Line":117
      }
    },
    "CustomMessage":"--"
  },
  "userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/84.0.4147.135 Safari/537.36",
  "version":"19.0.2.2"
}
@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

While browsing in messages, i can also observe some of these in Browser log:

XHR POST https://nextcloud.com/ocs/v2.php/apps/spreed/api/v2/room/8xmwbojf/participants/active
[HTTP/1.1 409 Conflict 217ms]

Followed by:

VM253 talk.js:716 POST https://nextcloud.com/ocs/v2.php/apps/spreed/api/v2/room/sp3ks9aw/participants/active 409 (Conflict)
(anonymous) @ VM253 talk.js:716
e.exports @ VM253 talk.js:716
e.exports @ VM253 talk.js:785
Promise.then (async)
c.request @ VM253 talk.js:785
r.forEach.c.<computed> @ VM253 talk.js:785
(anonymous) @ VM253 talk.js:716
(anonymous) @ VM253 talk.js:409
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
p @ VM253 talk.js:388
o @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:409
onRouteChange @ VM253 talk.js:1872
Ge @ VM253 talk.js:27
e.$emit @ VM253 talk.js:27
n @ VM253 talk.js:1916
(anonymous) @ VM253 talk.js:1916
d @ VM253 talk.js:1894
r @ VM253 talk.js:1894
r @ VM253 talk.js:1894
An @ VM253 talk.js:1894
bn.confirmTransition @ VM253 talk.js:1894
bn.transitionTo @ VM253 talk.js:1894
t.push @ VM253 talk.js:1894
Ln.push @ VM253 talk.js:1894
h @ VM253 talk.js:1894
Ge @ VM253 talk.js:27
n @ VM253 talk.js:27
i._wrapper @ VM253 talk.js:27

VM253 talk.js:716 GET https://nextcloud.com/ocs/v2.php/apps/spreed/api/v1/signaling/b3r22mnj 409 (Conflict)
(anonymous) @ VM253 talk.js:716
e.exports @ VM253 talk.js:716
e.exports @ VM253 talk.js:785
Promise.then (async)
c.request @ VM253 talk.js:785
r.forEach.c.<computed> @ VM253 talk.js:785
(anonymous) @ VM253 talk.js:716
(anonymous) @ VM253 talk.js:685
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
o @ VM253 talk.js:666
s @ VM253 talk.js:666
(anonymous) @ VM253 talk.js:666
(anonymous) @ VM253 talk.js:666
(anonymous) @ VM253 talk.js:685
(anonymous) @ VM253 talk.js:559
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
i @ VM253 talk.js:559
s @ VM253 talk.js:559
(anonymous) @ VM253 talk.js:559
(anonymous) @ VM253 talk.js:559
(anonymous) @ VM253 talk.js:559
A.Internal._startPullingMessages @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:176
Promise.then (async)
A.Internal._startPullingMessages @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:176
Promise.then (async)
A.Internal._startPullingMessages @ VM253 talk.js:176
A.Internal._joinRoomSuccess @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:176
A.Base.joinRoom @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:340
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
ae @ VM253 talk.js:320
o @ VM253 talk.js:320
Promise.then (async)
ae @ VM253 talk.js:320
o @ VM253 talk.js:320
(anonymous) @ VM253 talk.js:320
(anonymous) @ VM253 talk.js:320
xe @ VM253 talk.js:340
(anonymous) @ VM253 talk.js:409
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
p @ VM253 talk.js:388
o @ VM253 talk.js:388
Promise.then (async)
p @ VM253 talk.js:388
o @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:409
onRouteChange @ VM253 talk.js:1872
Ge @ VM253 talk.js:27
e.$emit @ VM253 talk.js:27
n @ VM253 talk.js:1916
(anonymous) @ VM253 talk.js:1916
d @ VM253 talk.js:1894
r @ VM253 talk.js:1894
An @ VM253 talk.js:1894
bn.confirmTransition @ VM253 talk.js:1894
bn.transitionTo @ VM253 talk.js:1894
t.push @ VM253 talk.js:1894
Ln.push @ VM253 talk.js:1894
h @ VM253 talk.js:1894
Ge @ VM253 talk.js:27
n @ VM253 talk.js:27
i._wrapper @ VM253 talk.js:27

VM253 talk.js:716 GET https://nextcloud.com/ocs/v2.php/apps/spreed/api/v1/signaling/s66pdx8t 404 (Not Found)
(anonymous) @ VM253 talk.js:716
e.exports @ VM253 talk.js:716
e.exports @ VM253 talk.js:785
Promise.then (async)
c.request @ VM253 talk.js:785
r.forEach.c.<computed> @ VM253 talk.js:785
(anonymous) @ VM253 talk.js:716
(anonymous) @ VM253 talk.js:685
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
o @ VM253 talk.js:666
s @ VM253 talk.js:666
(anonymous) @ VM253 talk.js:666
(anonymous) @ VM253 talk.js:666
(anonymous) @ VM253 talk.js:685
(anonymous) @ VM253 talk.js:559
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
i @ VM253 talk.js:559
s @ VM253 talk.js:559
(anonymous) @ VM253 talk.js:559
(anonymous) @ VM253 talk.js:559
(anonymous) @ VM253 talk.js:559
A.Internal._startPullingMessages @ VM253 talk.js:176
A.Internal._joinRoomSuccess @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:176
A.Base.joinRoom @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:340
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
ae @ VM253 talk.js:320
o @ VM253 talk.js:320
Promise.then (async)
ae @ VM253 talk.js:320
o @ VM253 talk.js:320
(anonymous) @ VM253 talk.js:320
(anonymous) @ VM253 talk.js:320
xe @ VM253 talk.js:340
(anonymous) @ VM253 talk.js:409
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
p @ VM253 talk.js:388
o @ VM253 talk.js:388
Promise.then (async)
p @ VM253 talk.js:388
o @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:409
onRouteChange @ VM253 talk.js:1872
Ge @ VM253 talk.js:27
e.$emit @ VM253 talk.js:27
n @ VM253 talk.js:1916
(anonymous) @ VM253 talk.js:1916
d @ VM253 talk.js:1894
r @ VM253 talk.js:1894
An @ VM253 talk.js:1894
bn.confirmTransition @ VM253 talk.js:1894
bn.transitionTo @ VM253 talk.js:1894
t.push @ VM253 talk.js:1894
Ln.push @ VM253 talk.js:1894
h @ VM253 talk.js:1894
Ge @ VM253 talk.js:27
n @ VM253 talk.js:27
i._wrapper @ VM253 talk.js:27

VM253 talk.js:176 Conversation was not found anymore
(anonymous) @ VM253 talk.js:176
Promise.catch (async)
A.Internal._startPullingMessages @ VM253 talk.js:176
A.Internal._joinRoomSuccess @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:176
A.Base.joinRoom @ VM253 talk.js:176
(anonymous) @ VM253 talk.js:340
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
ae @ VM253 talk.js:320
o @ VM253 talk.js:320
Promise.then (async)
ae @ VM253 talk.js:320
o @ VM253 talk.js:320
(anonymous) @ VM253 talk.js:320
(anonymous) @ VM253 talk.js:320
xe @ VM253 talk.js:340
(anonymous) @ VM253 talk.js:409
c @ VM253 talk.js:745
(anonymous) @ VM253 talk.js:745
forEach.e.<computed> @ VM253 talk.js:745
p @ VM253 talk.js:388
o @ VM253 talk.js:388
Promise.then (async)
p @ VM253 talk.js:388
o @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:388
(anonymous) @ VM253 talk.js:409
onRouteChange @ VM253 talk.js:1872
Ge @ VM253 talk.js:27
e.$emit @ VM253 talk.js:27
n @ VM253 talk.js:1916
(anonymous) @ VM253 talk.js:1916
d @ VM253 talk.js:1894
r @ VM253 talk.js:1894
An @ VM253 talk.js:1894
bn.confirmTransition @ VM253 talk.js:1894
bn.transitionTo @ VM253 talk.js:1894
t.push @ VM253 talk.js:1894
Ln.push @ VM253 talk.js:1894
h @ VM253 talk.js:1894
Ge @ VM253 talk.js:27
n @ VM253 talk.js:27
i._wrapper @ VM253 talk.js:27

VM253 talk.js:1916 Navigating away, leaving conversation
Navigated to https://nextcloud.com/apps/spreed/not-found
browserCheck.js:29 Detected browser Chrome 84 (84.0.4147.135)

Viewer.vue:210 Please do NOT wait for the DOMContentLoaded before registering your viewer handler
handlers @ Viewer.vue:210
fr.run @ vue.runtime.esm.js:4568
cr @ vue.runtime.esm.js:4310
(anonymous) @ vue.runtime.esm.js:1980
Ke @ vue.runtime.esm.js:1906
Promise.then (async)
Ge @ vue.runtime.esm.js:1933
tt @ vue.runtime.esm.js:1990
(anonymous) @ vue.runtime.esm.js:4402
fr.update @ vue.runtime.esm.js:4544
le.notify @ vue.runtime.esm.js:730
(anonymous) @ vue.runtime.esm.js:882
value @ Viewer.js:73
(anonymous) @ viewer.js?v=df14f6fb-74:109
onSuccess @ viewer.js?v=df14f6fb-74:51
c @ jquery.js:3099
fireWith @ jquery.js:3211
x @ jquery.js:8264
(anonymous) @ jquery.js:8605
load (async)
send @ jquery.js:8622
ajax @ jquery.js:8166
m.each.m.<computed> @ jquery.js:8311
OCA.Onlyoffice.GetSettings @ viewer.js?v=df14f6fb-74:47
initPage @ viewer.js?v=df14f6fb-74:103
c @ jquery.js:3099
fireWith @ jquery.js:3211
ready @ jquery.js:3417
P @ jquery.js:3433

@nickvergessen
Copy link
Member

Do you have a warning like the following in your admin settings?

Your database does not run with "READ COMMITTED" transaction isolation level. This can cause problems when multiple actions are executed in parallel.

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

No, DB is READ COMMITTED since the beginning.

MariaDB [(none)]> SHOW VARIABLES LIKE "tx_%";
+---------------+----------------+
| Variable_name | Value          |
+---------------+----------------+
| tx_isolation  | READ-COMMITTED |
| tx_read_only  | OFF            |
+---------------+----------------+

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

It seems problems were introduced since 19.0.2 upgrade (like nextcloud/server#22482) but they were submitted to the admins by users only today. Each user has an average of 20 active conversations.

@nickvergessen
Copy link
Member

Well this query here is totally unrelated to the files app. And I'm pretty sure that there was no related change on the database layer in the update

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

There wasn't also any change in our servers since months, others then applying security patches to the system.

Users all agree that problems started at the same moment 19.0.2 was introduced.
None of these problems were visible before that and everything was running smooth.

The problem is that even to get into (some) existing messages is impossible, as Nextcloud claims they not exist (but they do), but after refreshing the page, we can access them, but then we can't access other messages...etc. This is a mess :\

This is what we can see in browser log, no matter what browser, emptied caches, etc.

image

@nickvergessen
Copy link
Member

Can you check the table structure of your talk_participants database table and post the indexes it has?

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

MariaDB [ISnP3oT5]> SHOW INDEXES FROM oc_talk_participants;
+----------------------+------------+---------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| Table                | Non_unique | Key_name      | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
+----------------------+------------+---------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| oc_talk_participants |          0 | tp_ident      |            1 | room_id     | A         |         202 |     NULL | NULL   |      | BTREE      |         |               |
| oc_talk_participants |          0 | tp_ident      |            2 | user_id     | A         |         202 |     NULL | NULL   | YES  | BTREE      |         |               |
| oc_talk_participants |          0 | tp_ident      |            3 | session_id  | A         |         202 |     NULL | NULL   |      | BTREE      |         |               |
| oc_talk_participants |          1 | tp_room       |            1 | room_id     | A         |         202 |     NULL | NULL   |      | BTREE      |         |               |
| oc_talk_participants |          1 | tp_last_ping  |            1 | last_ping   | A         |         202 |     NULL | NULL   |      | BTREE      |         |               |
| oc_talk_participants |          1 | tp_in_call    |            1 | in_call     | A         |           2 |     NULL | NULL   |      | BTREE      |         |               |
| oc_talk_participants |          1 | tp_uid        |            1 | user_id     | A         |          40 |     NULL | NULL   | YES  | BTREE      |         |               |
| oc_talk_participants |          1 | tp_session_id |            1 | session_id  | A         |          40 |     NULL | NULL   |      | BTREE      |         |               |
+----------------------+------------+---------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
8 rows in set (0.001 sec)

@nickvergessen
Copy link
Member

So you said it started after the update to 19.0.2, did oyu run 19.0.0 or 19.0.1 before? Or an old 18.0.x version?

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

All upgrades had been made since v18, minor by minor (18.0.1, 18.0.2......19.0.0, 19.0.1, 19.0.2).
No errors were produced, and all upgrades are (always) made by CLI only.

@nickvergessen
Copy link
Member

nickvergessen commented Sep 3, 2020

In lib/private/DB/Connection.php after line:
https://github.com/nextcloud/server/blob/caff1023ea72bb2ea94130e18a2a6e2ccf819e5f/lib/private/DB/Connection.php#L151

$this->tablePrefix = $params['tablePrefix'];

can you add:

$this->setTransactionIsolation(\Doctrine\DBAL\TransactionIsolationLevel::READ_COMMITTED);

And see if that solves the issue?

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

PHP Fatal error: Uncaught Error: Class 'OC\DB\TransactionIsolationLevel' not found

@nickvergessen
Copy link
Member

nickvergessen commented Sep 3, 2020

Ah in the meantime the import was removed, try:

$this->setTransactionIsolation(\Doctrine\DBAL\TransactionIsolationLevel::READ_COMMITTED);

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

No, same behavior (i've removed the extra ; in the meanwhile).

@solracsf
Copy link
Member Author

solracsf commented Sep 3, 2020

Please also note that errors like Deadlock found when trying to get lock are not very frequent; what we observe are the Browser errors in the first posts. deadlock ones are those we've found about oc_talk_participants and we've reported them.

Nginx, MariaDB, PHP, Redis and Nextcloud error logs are all of them silent when these errors occur on the front end.
Nginx access logs report a lot of 404 (room not found?) and 409 (Conflict).

@nickvergessen
Copy link
Member

yeah but the 404 and 409 happen because setting your session fails

@solracsf
Copy link
Member Author

solracsf commented Sep 30, 2020

I've set up a dedicated Signaling server.
image

After that, i can browse conversations without any errors (double session, participants not found, etc).
If i remove Signaling settings, errors are back.

@nickvergessen

This comment has been minimized.

@solracsf

This comment has been minimized.

@nickvergessen
Copy link
Member

Is this still happening in the newest 10.0.5 version or maybe one can even try the 11.0.0-alpha.3?

@svseidel
Copy link

Is this still happening in the newest 10.0.5 version or maybe one can even try the 11.0.0-alpha.3?

Yes, unfortunately, in 10.0.5. (in my case: nextcloud/server#25075)

@solracsf
Copy link
Member Author

I can't tell, since #4093 (comment)

@no-response no-response bot removed the needs info label Jan 19, 2021
@nickvergessen
Copy link
Member

Seems to not happen anymore with later nextcloud versions.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0. Needs triage bug feature: api 🛠️ OCS API for conversations, chats and participants
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants