A Little Story

To the Code!

@Transactional
fun signup(name: String) {
// shortened
val user = userRepository.save(
User(
name = name,
signupDateTime = LocalDateTime.now()
)
)
// NOTE: this uses @Transactional(propagation = REQUIRES_NEW)
userLogService.logUserAction(user.id!!, "User signed up")
// shortened
}

What’s the Problem here?

INSERT INTO USER (id, name) VALUES (1, 'foo');
-- no commit yet
INSERT INTO USER_LOG
(id, user_id, message)
VALUES
(123, 1, 'message');
COMMIT;
Typical circular waiting deadlock pattern

“But I would never write this Code”

Reality Check

  • Our application (the request-thread, and db-connections) will be blocked for several seconds typically.
  • The action we tried to take (db write operations) will fail.

So how would we even find this Issue in our Code?

Simplified & annotated Stacktrace
SHOW FULL PROCESSLIST;
SHOW ENGINE INNODB STATUS;
SELECT r.trx_id              waiting_trx_id,
r.trx_mysql_thread_id waiting_thread,
r.trx_query waiting_query,
b.trx_id blocking_trx_id,
b.trx_mysql_thread_id blocking_thread,
b.trx_query blocking_query
FROM information_schema.innodb_lock_waits w
INNER JOIN information_schema.innodb_trx b
ON b.trx_id = w.blocking_trx_id
INNER JOIN information_schema.innodb_trx r
ON r.trx_id = w.requesting_trx_id;
Result of the blocking connection analysis query

How do we fix this?

// Propagation.MANDATORY makes sure a transaction is ongoing
// so we have something to "sync to"
@Transactional(propagation = Propagation.MANDATORY)
fun logUserActionFixed(userId: Long, action: String) {
LOG.info("logUserActionFixed start for userId {} and action {}",
userId, action)

TransactionSynchronizationManager
.registerSynchronization(object : TransactionSynchronization {
override fun afterCompletion(status: Int) {
// NOTE: we could even check if the initial transaction
// failed or succeeded via the status parameter
LOG.info("starting actual logging to repository")
userLogRepository.save(
UserLog(
userId = userId,
dateTime = LocalDateTime.now(),
log = action
)
)
LOG.info("actual logging to repository done")
}
})

LOG.info("logUserActionFixed done (no actual logging yet)")
}

Wrapping up

@Transactional(propagation = Propagation.REQUIRES_NEW)
  • Were these potential problems considered when writing this code?
  • How is the DB-pool configured?
  • Is concurrency limited when it comes to calling this code?
  • What data (tables) is accessed inside this code and which ones outside (before) calling this? Typically we only care about write-access here.

--

--

--

Software engineer from Austria. Passionate about software, likes photography, addicted to podcasts and always busy. http://paukl.at

Love podcasts or audiobooks? Learn on the go with our new app.

Recommended from Medium

CS373 Spring 2020: Rithvik Saravanan — Blog Post #11

Performance tuning in PostGreSQL DB

Saving the (Dev) Environment

Community Incentives Program (CIP) December Update!

Breadth First Search in Swift

Understanding DBSCAN Algorithm and Implementation from Scratch

Bold wholesale customer pricing — Is there any alternative solution???

Coding a production ready API — part 1: implementing an ORM

Get the Medium app

A button that says 'Download on the App Store', and if clicked it will lead you to the iOS App store
A button that says 'Get it on, Google Play', and if clicked it will lead you to the Google Play store
Paul Klingelhuber

Paul Klingelhuber

Software engineer from Austria. Passionate about software, likes photography, addicted to podcasts and always busy. http://paukl.at

More from Medium

Lexorank — Managing Sorted Tables With Ease

Reactor API part 1

A Modern Approach to using OpenCL with C++ on Android and Unix.

multithreading