MySQL Deadlock when attempting to delete stations

ItsMitchh commented 3 years ago

Installation Method

Docker Installation

AzuraCast Release Channel

Rolling Release Channel

Current AzuraCast Version

Rolling Release #9bbae3d

What happened?

A Slim Application Error and MySQL deadlock occurs when I attempt to delete the station provided (Station ID 87) as seen in the large logs I'm providing.

The Audit Log confirmed I deleted the station but it still flooded with Slim Application Errors and MySQL deadlocks.

Relevant log output

Me deleting the station
nginx_proxy                | nginx.1     | crosshost.ml SNIP - - [09/Sep/2021:16:05:14 +0000] "GET /admin/stations/delete/87/pgppxEt417 HTTP/2.0" 500 602 "https://crosshost.ml/admin/stations" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/93.0.4577.63 Safari/537.36 Edg/93.0.961.38"
---
The correct HTTP error returns
web_1                      | [2021-09-09T16:06:11.947194+00:00] AzuraCast.ERROR: HTTP client GET call to http://stations:8210/admin/stats produced response NULL [] {"station":{"id":87,"name":"Mango 🥭"}}
web_1                      | [2021-09-09T16:06:11.948976+00:00] AzuraCast.ERROR: NowPlaying adapter error: cURL error 7: Failed to connect to stations port 8210: Connection refused (see https://curl.haxx.se/libcurl/c/libcurl-errors.html)
---

Super huge error and it returns Slim Application Error
web_1                      | [2021-09-09T16:07:24.252981+00:00] AzuraCast.ERROR: Doctrine\DBAL\Exception\DeadlockException: An exception occurred while executing 'UPDATE station SET nowplaying = ?, nowplaying_timestamp = ? WHERE id = ?' with params ["O:36:\"App\\Entity\\Api\\NowPlaying\\NowPlaying\":8:{s:7:\"station\";O:33:\"App\\Entity\\Api\\NowPlaying\\Station\":14:{s:2:\"id\";i:87;s:4:\"name\";s:10:\"Mango \ud83e\udd6d\";s:9:\"shortcode\";s:5:\"mango\";s:11:\"description\";s:0:\"\";s:8:\"frontend\";s:7:\"icecast\";s:7:\"backend\";s:10:\"liquidsoap\";s:10:\"listen_url\";O:19:\"GuzzleHttp\\Psr7\\Uri\":7:{s:27:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000scheme\";s:0:\"\";s:29:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000userInfo\";s:0:\"\";s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000host\";s:0:\"\";s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000port\";N;s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000path\";s:21:\"\/radio\/8210\/radio.mp3\";s:26:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000query\";s:0:\"\";s:29:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000fragment\";s:0:\"\";}s:3:\"url\";s:0:\"\";s:17:\"public_player_url\";s:13:\"\/public\/mango\";s:16:\"playlist_pls_url\";s:26:\"\/public\/mango\/playlist.pls\";s:16:\"playlist_m3u_url\";s:26:\"\/public\/mango\/playlist.m3u\";s:9:\"is_public\";b:1;s:6:\"mounts\";a:1:{i:0;O:38:\"App\\Entity\\Api\\NowPlaying\\StationMount\":8:{s:4:\"path\";s:10:\"\/radio.mp3\";s:10:\"is_default\";b:1;s:2:\"id\";i:92;s:4:\"name\";s:11:\"128kbps MP3\";s:3:\"url\";O:19:\"GuzzleHttp\\Psr7\\Uri\":7:{s:27:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000scheme\";s:0:\"\";s:29:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000userInfo\";s:0:\"\";s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000host\";s:0:\"\";s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000port\";N;s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000path\";s:21:\"\/radio\/8210\/radio.mp3\";s:26:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000query\";s:0:\"\";s:29:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000fragment\";s:0:\"\";}s:7:\"bitrate\";i:128;s:6:\"format\";s:3:\"mp3\";s:9:\"listeners\";O:35:\"App\\Entity\\Api\\NowPlaying\\Listeners\":3:{s:5:\"total\";i:0;s:6:\"unique\";i:0;s:7:\"current\";i:0;}}}s:7:\"remotes\";a:0:{}}s:9:\"listeners\";O:35:\"App\\Entity\\Api\\NowPlaying\\Listeners\":3:{s:5:\"total\";i:0;s:6:\"unique\";i:0;s:7:\"current\";i:0;}s:4:\"live\";O:30:\"App\\Entity\\Api\\NowPlaying\\Live\":3:{s:7:\"is_live\";b:0;s:13:\"streamer_name\";s:0:\"\";s:15:\"broadcast_start\";N;}s:11:\"now_playing\";O:37:\"App\\Entity\\Api\\NowPlaying\\CurrentSong\":9:{s:7:\"elapsed\";i:1631203649;s:9:\"remaining\";i:0;s:5:\"sh_id\";i:0;s:9:\"played_at\";i:0;s:8:\"duration\";i:0;s:8:\"playlist\";N;s:8:\"streamer\";N;s:10:\"is_request\";b:0;s:4:\"song\";O:19:\"App\\Entity\\Api\\Song\":9:{s:2:\"id\";s:32:\"7a1230502efebe8990578f71285bcf46\";s:4:\"text\";s:17:\" - Stream Offline\";s:6:\"artist\";s:0:\"\";s:5:\"title\";s:14:\"Stream Offline\";s:5:\"album\";s:0:\"\";s:5:\"genre\";s:0:\"\";s:6:\"lyrics\";s:0:\"\";s:3:\"art\";O:19:\"GuzzleHttp\\Psr7\\Uri\":7:{s:27:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000scheme\";s:0:\"\";s:29:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000userInfo\";s:0:\"\";s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000host\";s:0:\"\";s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000port\";N;s:25:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000path\";s:28:\"\/static\/img\/generic_song.jpg\";s:26:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000query\";s:0:\"\";s:29:\"\u0000GuzzleHttp\\Psr7\\Uri\u0000fragment\";s:0:\"\";}s:13:\"custom_fields\";a:0:{}}}s:12:\"playing_next\";N;s:12:\"song_history\";a:0:{}s:9:\"is_online\";b:0;s:5:\"cache\";N;}", 1631203644, 87]:  SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction (uncaught exception) at /var/azuracast/www/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/AbstractMySQLDriver.php line 51 while running console command `sync:run` {"exception":"[object] (Doctrine\\DBAL\\Exception\\DeadlockException(code: 0): An exception occurred while executing 'UPDATE station SET nowplaying = ?, nowplaying_timestamp = ? WHERE id = ?' with params [\"O:36:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\NowPlaying\\\":8:{s:7:\\\"station\\\";O:33:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\Station\\\":14:{s:2:\\\"id\\\";i:87;s:4:\\\"name\\\";s:10:\\\"Mango \\ud83e\\udd6d\\\";s:9:\\\"shortcode\\\";s:5:\\\"mango\\\";s:11:\\\"description\\\";s:0:\\\"\\\";s:8:\\\"frontend\\\";s:7:\\\"icecast\\\";s:7:\\\"backend\\\";s:10:\\\"liquidsoap\\\";s:10:\\\"listen_url\\\";O:19:\\\"GuzzleHttp\\\\Psr7\\\\Uri\\\":7:{s:27:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000scheme\\\";s:0:\\\"\\\";s:29:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000userInfo\\\";s:0:\\\"\\\";s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000host\\\";s:0:\\\"\\\";s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000port\\\";N;s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000path\\\";s:21:\\\"\\/radio\\/8210\\/radio.mp3\\\";s:26:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000query\\\";s:0:\\\"\\\";s:29:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000fragment\\\";s:0:\\\"\\\";}s:3:\\\"url\\\";s:0:\\\"\\\";s:17:\\\"public_player_url\\\";s:13:\\\"\\/public\\/mango\\\";s:16:\\\"playlist_pls_url\\\";s:26:\\\"\\/public\\/mango\\/playlist.pls\\\";s:16:\\\"playlist_m3u_url\\\";s:26:\\\"\\/public\\/mango\\/playlist.m3u\\\";s:9:\\\"is_public\\\";b:1;s:6:\\\"mounts\\\";a:1:{i:0;O:38:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\StationMount\\\":8:{s:4:\\\"path\\\";s:10:\\\"\\/radio.mp3\\\";s:10:\\\"is_default\\\";b:1;s:2:\\\"id\\\";i:92;s:4:\\\"name\\\";s:11:\\\"128kbps MP3\\\";s:3:\\\"url\\\";O:19:\\\"GuzzleHttp\\\\Psr7\\\\Uri\\\":7:{s:27:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000scheme\\\";s:0:\\\"\\\";s:29:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000userInfo\\\";s:0:\\\"\\\";s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000host\\\";s:0:\\\"\\\";s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000port\\\";N;s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000path\\\";s:21:\\\"\\/radio\\/8210\\/radio.mp3\\\";s:26:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000query\\\";s:0:\\\"\\\";s:29:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000fragment\\\";s:0:\\\"\\\";}s:7:\\\"bitrate\\\";i:128;s:6:\\\"format\\\";s:3:\\\"mp3\\\";s:9:\\\"listeners\\\";O:35:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\Listeners\\\":3:{s:5:\\\"total\\\";i:0;s:6:\\\"unique\\\";i:0;s:7:\\\"current\\\";i:0;}}}s:7:\\\"remotes\\\";a:0:{}}s:9:\\\"listeners\\\";O:35:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\Listeners\\\":3:{s:5:\\\"total\\\";i:0;s:6:\\\"unique\\\";i:0;s:7:\\\"current\\\";i:0;}s:4:\\\"live\\\";O:30:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\Live\\\":3:{s:7:\\\"is_live\\\";b:0;s:13:\\\"streamer_name\\\";s:0:\\\"\\\";s:15:\\\"broadcast_start\\\";N;}s:11:\\\"now_playing\\\";O:37:\\\"App\\\\Entity\\\\Api\\\\NowPlaying\\\\CurrentSong\\\":9:{s:7:\\\"elapsed\\\";i:1631203649;s:9:\\\"remaining\\\";i:0;s:5:\\\"sh_id\\\";i:0;s:9:\\\"played_at\\\";i:0;s:8:\\\"duration\\\";i:0;s:8:\\\"playlist\\\";N;s:8:\\\"streamer\\\";N;s:10:\\\"is_request\\\";b:0;s:4:\\\"song\\\";O:19:\\\"App\\\\Entity\\\\Api\\\\Song\\\":9:{s:2:\\\"id\\\";s:32:\\\"7a1230502efebe8990578f71285bcf46\\\";s:4:\\\"text\\\";s:17:\\\" - Stream Offline\\\";s:6:\\\"artist\\\";s:0:\\\"\\\";s:5:\\\"title\\\";s:14:\\\"Stream Offline\\\";s:5:\\\"album\\\";s:0:\\\"\\\";s:5:\\\"genre\\\";s:0:\\\"\\\";s:6:\\\"lyrics\\\";s:0:\\\"\\\";s:3:\\\"art\\\";O:19:\\\"GuzzleHttp\\\\Psr7\\\\Uri\\\":7:{s:27:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000scheme\\\";s:0:\\\"\\\";s:29:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000userInfo\\\";s:0:\\\"\\\";s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000host\\\";s:0:\\\"\\\";s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000port\\\";N;s:25:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000path\\\";s:28:\\\"\\/static\\/img\\/generic_song.jpg\\\";s:26:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000query\\\";s:0:\\\"\\\";s:29:\\\"\\u0000GuzzleHttp\\\\Psr7\\\\Uri\\u0000fragment\\\";s:0:\\\"\\\";}s:13:\\\"custom_fields\\\";a:0:{}}}s:12:\\\"playing_next\\\";N;s:12:\\\"song_history\\\";a:0:{}s:9:\\\"is_online\\\";b:0;s:5:\\\"cache\\\";N;}\", 1631203644, 87]:\n\nSQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction at /var/azuracast/www/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/AbstractMySQLDriver.php:51)\n[previous exception] [object] (Doctrine\\DBAL\\Driver\\PDO\\Exception(code: 40001): SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction at /var/azuracast/www/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDO/Exception.php:18)\n[previous exception] [object] (PDOException(code: 40001): SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction at /var/azuracast/www/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php:112)"} {"station":{"id":87,"name":"Mango 🥭"}}

Vaalyn commented 3 years ago

I'm not sure why you are seeing a Slim Application Error when deleting the station since the Deadlock is happening for a Now Playing update according to the log and the delete action for a station does not execute a now playing update.

I couldn't reproduce this error on my test server. Are you able to consistently reproduce this?

ItsMitchh commented 3 years ago

Sadly not, which makes this issue fairly frustrating to replicate because I got no idea of the exact cause. I can do some more testing later tonight to see if I can reproduce this.

BusterNeece commented 3 years ago

Wondering if basically, during operations like station deleting, we need to prevent the regular sync tasks from happening at the same time, because they would definitely run up against each other in weird ways otherwise.

github-actions[bot] commented 2 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

AzuraCast / AzuraCast