github.com/blend/go-sdk@v1.20220411.3/examples/db/prevent-deadlock/README.md (about) 1 # Preventing Deadlock with Lock Timeout 2 3 ## Prerequisites 4 5 Set some common environment variables (we `export` here to make running 6 the Go script a bit simpler, but these can be local in a shell or local 7 to a command) 8 9 ``` 10 export DB_HOST=localhost 11 export DB_PORT=28007 12 export DB_USER=superuser 13 export DB_NAME=superuser_db 14 export DB_PASSWORD=testpassword_superuser 15 export DB_SSLMODE=disable 16 ``` 17 18 and make sure a local `postgres` server is running 19 20 ``` 21 docker run \ 22 --detach \ 23 --hostname "${DB_HOST}" \ 24 --publish "${DB_PORT}:5432" \ 25 --name dev-postgres-prevent-deadlock \ 26 --env "POSTGRES_DB=${DB_NAME}" \ 27 --env "POSTGRES_USER=${DB_USER}" \ 28 --env "POSTGRES_PASSWORD=${DB_PASSWORD}" \ 29 postgres:10.6-alpine 30 ``` 31 32 ## Intentional Contention 33 34 In order to introduce a deadlock, we borrow an example from 35 [When Postgres blocks: 7 tips for dealing with locks][6]. 36 37 In the first transaction we update "hello" rows following by "world" rows 38 39 ```sql 40 BEGIN; 41 UPDATE might_deadlock SET counter = counter + 1 WHERE key = 'hello'; 42 -- Sleep for configured transaction sleep 43 UPDATE might_deadlock SET counter = counter + 1 WHERE key = 'world'; 44 COMMIT; 45 ``` 46 47 and in the second transaction we update the rows in the opposite order 48 49 ```sql 50 BEGIN; 51 UPDATE might_deadlock SET counter = counter + 1 WHERE key = 'world'; 52 -- Sleep for configured transaction sleep 53 UPDATE might_deadlock SET counter = counter + 1 WHERE key = 'hello'; 54 COMMIT; 55 ``` 56 57 ## Let `postgres` Cancel Via `lock_timeout` 58 59 ``` 60 $ go run . 61 0.000055 ================================================== 62 0.000085 Configured lock timeout: 10ms 63 0.000089 Configured context timeout: 600ms 64 0.000091 Configured transaction sleep: 200ms 65 0.000114 ================================================== 66 0.014372 DSN="postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&lock_timeout=10ms&sslmode=disable" 67 0.014381 ================================================== 68 0.015569 lock_timeout=10ms 69 0.026958 ================================================== 70 0.026981 Starting transactions 71 0.036223 Transactions opened 72 0.261793 *** 73 0.261803 Error(s): 74 0.261852 - &pq.Error{Severity:"ERROR", Code:"55P03", Message:"canceling statement due to lock timeout", Detail:"", Hint:"", Position:"", InternalPosition:"", InternalQuery:"", Where:"while updating tuple (0,2) in relation \"might_deadlock\"", Schema:"", Table:"", Column:"", DataTypeName:"", Constraint:"", File:"postgres.c", Line:"2989", Routine:"ProcessInterrupts"} 75 0.261862 - &pq.Error{Severity:"ERROR", Code:"55P03", Message:"canceling statement due to lock timeout", Detail:"", Hint:"", Position:"", InternalPosition:"", InternalQuery:"", Where:"while updating tuple (0,1) in relation \"might_deadlock\"", Schema:"", Table:"", Column:"", DataTypeName:"", Constraint:"", File:"postgres.c", Line:"2989", Routine:"ProcessInterrupts"} 76 ``` 77 78 From [Appendix A. PostgreSQL Error Codes][1]: 79 80 ``` 81 Class 55 - Object Not In Prerequisite State 82 ---------+---------------------------------- 83 55P03 | lock_not_available 84 ``` 85 86 ## Force a Deadlock 87 88 By allowing the Go context to stay active for **very** long, we can allow 89 Postgres to detect 90 91 ``` 92 $ FORCE_DEADLOCK=true go run . 93 0.000044 ================================================== 94 0.000068 Configured lock timeout: 10s 95 0.000071 Configured context timeout: 10s 96 0.000073 Configured transaction sleep: 200ms 97 0.000089 ================================================== 98 0.011839 DSN="postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&lock_timeout=10000ms&sslmode=disable" 99 0.011850 ================================================== 100 0.013332 lock_timeout=10s 101 0.022643 ================================================== 102 0.022659 Starting transactions 103 0.030515 Transactions opened 104 1.245005 *** 105 1.245016 Error(s): 106 1.245053 - &pq.Error{Severity:"ERROR", Code:"40P01", Message:"deadlock detected", Detail:"Process 347 waits for ShareLock on transaction 845; blocked by process 346.\nProcess 346 waits for ShareLock on transaction 846; blocked by process 347.", Hint:"See server log for query details.", Position:"", InternalPosition:"", InternalQuery:"", Where:"while updating tuple (0,1) in relation \"might_deadlock\"", Schema:"", Table:"", Column:"", DataTypeName:"", Constraint:"", File:"deadlock.c", Line:"1140", Routine:"DeadLockReport"} 107 ``` 108 109 From [Appendix A. PostgreSQL Error Codes][1]: 110 111 ``` 112 Class 40 - Transaction Rollback 113 ---------+---------------------- 114 40P01 | deadlock_detected 115 ``` 116 117 ## Go `context` Cancelation In Between Queries in a Transaction 118 119 ``` 120 $ BETWEEN_QUERIES=true go run . 121 0.000051 ================================================== 122 0.000082 Configured lock timeout: 10s 123 0.000086 Configured context timeout: 100ms 124 0.000089 Configured transaction sleep: 200ms 125 0.000110 ================================================== 126 0.013163 DSN="postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&lock_timeout=10000ms&sslmode=disable" 127 0.013176 ================================================== 128 0.014402 lock_timeout=10s 129 0.025375 ================================================== 130 0.025401 Starting transactions 131 0.032665 Transactions opened 132 0.236497 *** 133 0.236519 Error(s): 134 0.236575 - context.deadlineExceededError{} 135 0.236587 - Context cancel in between queries 136 0.236591 - context.deadlineExceededError{} 137 0.236615 - Context cancel in between queries 138 ``` 139 140 ## Cancel "Stuck" Deadlock via Go `context` Cancelation 141 142 ``` 143 $ DISABLE_LOCK_TIMEOUT=true go run . 144 0.000053 ================================================== 145 0.000084 Configured lock timeout: 10s 146 0.000088 Configured context timeout: 600ms 147 0.000091 Configured transaction sleep: 200ms 148 0.000113 ================================================== 149 0.014431 DSN="postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&lock_timeout=10000ms&sslmode=disable" 150 0.014442 ================================================== 151 0.016239 lock_timeout=10s 152 0.026890 ================================================== 153 0.026903 Starting transactions 154 0.036405 Transactions opened 155 0.612462 *** 156 0.612474 Error(s): 157 0.612539 - &pq.Error{Severity:"ERROR", Code:"57014", Message:"canceling statement due to user request", Detail:"", Hint:"", Position:"", InternalPosition:"", InternalQuery:"", Where:"while updating tuple (0,2) in relation \"might_deadlock\"", Schema:"", Table:"", Column:"", DataTypeName:"", Constraint:"", File:"postgres.c", Line:"3026", Routine:"ProcessInterrupts"} 158 0.612556 - &pq.Error{Severity:"ERROR", Code:"57014", Message:"canceling statement due to user request", Detail:"", Hint:"", Position:"", InternalPosition:"", InternalQuery:"", Where:"while updating tuple (0,1) in relation \"might_deadlock\"", Schema:"", Table:"", Column:"", DataTypeName:"", Constraint:"", File:"postgres.c", Line:"3026", Routine:"ProcessInterrupts"} 159 ``` 160 161 From [Appendix A. PostgreSQL Error Codes][1]: 162 163 ``` 164 Class 57 - Operator Intervention 165 ---------+----------------------- 166 57014 | query_canceled 167 ``` 168 169 ## `psql` Does **NOT** Support `lock_timeout` in DSN 170 171 See `libpq` [Parameter Key Words][2] 172 173 ``` 174 $ psql "postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&lock_timeout=10ms&sslmode=disable" 175 psql: error: could not connect to server: invalid URI query parameter: "lock_timeout" 176 $ 177 $ 178 $ psql "postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&sslmode=disable" 179 ... 180 superuser_db=# SHOW lock_timeout; 181 lock_timeout 182 -------------- 183 0 184 (1 row) 185 186 superuser_db=# \q 187 $ 188 $ 189 $ PGOPTIONS="-c lock_timeout=4500ms" psql "postgres://superuser:testpassword_superuser@localhost:28007/superuser_db?connect_timeout=5&sslmode=disable" 190 ... 191 superuser_db=# SHOW lock_timeout; 192 lock_timeout 193 -------------- 194 4500ms 195 (1 row) 196 197 superuser_db=# \q 198 ``` 199 200 Instead `github.com/lib/pq` parses all query parameters when [reading a DSN][3] 201 (data source name) and then passes all non-driver setting through as key-value 202 pairs when [forming a startup packet][4]. The designated driver settings 203 [are][5]: 204 205 - `host` 206 - `port` 207 - `password` 208 - `sslmode` 209 - `sslcert` 210 - `sslkey` 211 - `sslrootcert` 212 - `fallback_application_name` 213 - `connect_timeout` 214 - `disable_prepared_binary_result` 215 - `binary_parameters` 216 - `krbsrvname` 217 - `krbspn` 218 219 From the [Start-up][7] section of the documentation for 220 "Frontend/Backend Protocol > Message Flow", we see 221 222 > To begin a session, a frontend opens a connection to the server and sends a 223 > startup message ... (Optionally, the startup message can include additional 224 > settings for run-time parameters.) 225 226 This is why using `PGOPTIONS="-c {key}={value}"` is required for [setting][8] 227 named run-time parameters. It's also worth noting that `github.com/lib/pq` 228 is [`PGOPTIONS`-aware][9]. 229 230 ## Clean Up 231 232 ``` 233 docker rm --force dev-postgres-prevent-deadlock 234 ``` 235 236 [1]: https://www.postgresql.org/docs/10/errcodes-appendix.html 237 [2]: https://www.postgresql.org/docs/10/libpq-connect.html#LIBPQ-PARAMKEYWORDS 238 [3]: https://github.com/lib/pq/blob/v1.8.0/connector.go#L67-L69 239 [4]: https://github.com/lib/pq/blob/v1.8.0/conn.go#L1093-L1105 240 [5]: https://github.com/lib/pq/blob/v1.8.0/conn.go#L1058-L1084 241 [6]: https://www.citusdata.com/blog/2018/02/22/seven-tips-for-dealing-with-postgres-locks/ 242 [7]: https://www.postgresql.org/docs/10/protocol-flow.html#id-1.10.5.7.3 243 [8]: https://www.postgresql.org/docs/10/app-postgres.html#id-1.9.5.13.6.3 244 [9]: https://github.com/lib/pq/blob/v1.8.0/conn.go#L1945-L1946