Recovery from problems: cannot catch an unhandled exception from sqljocky5

[hoylen]

I have a Dart Web server that should keep running, even if the MySQL/MariaDB cannot be contacted (e.g. it is restarted for maintenance or there are intermittent network issues). When the database becomes available again, the program should be able to recover and continue running.

Unfortunately, there is at least one situation where sqljocky5 v2.2.1 throws an exception that terminates the Dart program. I have found no way to catch the exception to ignore it.

It happens in this scenario:

1. A connection to the database is successfully opened.
2. A transaction is successfully created on that connection.
3. The database somehow stops running.
4. An attempt to run a query on the transaction and the exception is raised.

The program prints the following and exits:

Unhandled exception:
SocketException: Write failed (OS Error: Broken pipe, errno = 32), address = database.example.com, port = 62372
#0      _rootHandleUncaughtError.<anonymous closure> (dart:async/zone.dart:1112:29)
#1      _microtaskLoop (dart:async/schedule_microtask.dart:41:21)
#2      _startMicrotaskLoop (dart:async/schedule_microtask.dart:50:5)
#3      _runPendingImmediateCallback (dart:isolate/runtime/libisolate_patch.dart:115:13)
#4      _RawReceivePortImpl._handleMessage (dart:isolate/runtime/libisolate_patch.dart:172:5)

I have written a demo program to test this scenario (and recovery from other failure modes):
https://github.com/hoylen/sqljocky5-recovery

[tejainece]

@hoylen I am not able to reproduce this issue. I created a simple example here: https://github.com/dart-db/sqljocky5/blob/master/example/disconnect_transaction.dart

It properly it hits this catch statement: https://github.com/dart-db/sqljocky5/blob/master/example/disconnect_transaction.dart#L43

I shutdown MySQL server after the transaction is started and before the transaction query is executed.

Can you please point me in the right direction?

Thanks!

[hoylen]

This issue doesn't seem to be deterministic: sometimes it happens and sometimes it doesn't. This morning, I couldn't reproduce it; then for a while it was happening about 1/3 of the time; and for a long while I couldn't reproduce it again, and now it is occasionally happening again! I don't know what causes it to happen or what has changed to affect how frequently it happens.

You might be running MySQL/MariaDB on the same machine as the client, but I don't know if that is a factor. I've tested it with it running on a different host: connecting to it directly as well as connecting to it via a SSH tunnel. I've also tried killing the database with "systemctl stop", "kill -9", and rebooting the host.

I'm using MariaDB 10.2 running on CentOS 7 on the server. On the client I've tried both Dart 2.1.0 and Dart 2.0.0, as well as running from the command line or in the WebStorm IDE.

Reliable trigger

I have discovered one method to reliably trigger it (or something like it, since this is not how I found it yesterday):

1. Have the database run on a different host machine, and create a ssh tunnel to connect to it (e.g. ssh -L 9999:localhost:3306 [email protected].
2. Then run either test programs to open a connection to localhost port 9999.
3. Kill the connection with "exit" on the ssh session and you might have to ^C the ssh client process.
4. Continue with the test program, attempting to execute a query on the previously opened connection and transaction. This produces the unhandled exception.

Unreliable trigger

As I write this, it is occasionally happening again. I've updated my test program, added a modified version of your test program, and created some helper shell scripts, at https://github.com/hoylen/sqljocky5-recovery.

I run my db-start-stop.sh script on the server (using sudo or as root), which randomly starts and stops the mysqld.

On the client, I run my test program in continuous-loop mode:

dart dbrecovery.dart -c beforeQuery

Or run a modified version of your test program as a continuous-loop and in non-interactive mode (waiting 4 seconds before executing the query and before opening a new connection):

dart disconnect_transaction.dart -c 4

If the "unhandled exception" happens, the test programs halt, otherwise they keep trying to trigger the issue. So you can leave the running and come back later to see if the problem ever got triggered.

So far, it has occasionally triggered with my test program, but I have not yet seen it happen with your test program.

[tejainece]

It would be very helpful if you can trim down the testcase to bare minimum.

[hoylen]

I'll work on it. I spent most of today trying to get it to trigger, but since it is not deterministic it is hard to tell what is going on.

[tejainece]

Hi,

Sorry I did not notice that you have updated the repo. It is very concise and clear. And I am now able to reproduce it.

I will try to fix it.

[hoylen]

Oh good.

I assume you mean the modified version of your disconnect_transact.dart. That is good, since I have not yet seen it randomly fail (only have had it fail by closing the SSH tunnel on it).

[tejainece]

I get an exception. not exactly the one you have posted. But it is still Unhandled exception.

I did not yet succeed to catch this exception properly. Starting to think, this is something to do with Dart SDK.

[tejainece]

Here is another occurrence of the same error: dartist/redis_client#67

[tejainece]

Have created this issue: dart-lang/sdk#35995