Bug #88523 InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the serv
Submitted: 16 Nov 2017 14:13 Modified: 26 Sep 2018 13:14
Reporter: Kevin F Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.16/5.7.22 OS:Microsoft Windows
Assigned to: CPU Architecture:Any

[16 Nov 2017 14:13] Kevin F
Description:
MySQL server is now restarting itself every 18minutes or so with the following in the error log:
InnoDB: ###### Diagnostic info printed to the standard error stream
2017-11-16T13:18:39.650036Z 0 [ERROR] [FATAL] InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the server because it appears to be hung.
2017-11-16 13:18:39 0x1bcc  InnoDB: Assertion failure in thread 7116 in file ut0ut.cc line 916
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
13:18:39 UTC - mysqld got exception 0x80000003 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=34
max_threads=151
thread_count=6
connection_count=6
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68011 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
7ff7eeb7e262    mysqld.exe!my_sigabrt_handler()[my_thr_init.c:449]
7ff7eef28489    mysqld.exe!raise()[winsig.c:587]
7ff7eef27380    mysqld.exe!abort()[abort.c:82]
7ff7eec8f178    mysqld.exe!ut_dbg_assertion_failed()[ut0dbg.cc:67]
7ff7eec8f391    mysqld.exe!ib::fatal::~fatal()[ut0ut.cc:916]
7ff7eebfd43d    mysqld.exe!srv_error_monitor_thread()[srv0srv.cc:1724]
7ffc55d613d2    KERNEL32.DLL!BaseThreadInitThunk()
7ffc57d854e4    ntdll.dll!RtlUserThreadStart()
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.

There appears to be a transaction which is being rolled back when the server restarts. The following can be found in the information_schema.innodb_trx\G

                    trx_id: 309725166
                 trx_state: ROLLING BACK
               trx_started: 2017-11-16 13:30:18
     trx_requested_lock_id: NULL
          trx_wait_started: NULL
                trx_weight: 17856930
       trx_mysql_thread_id: 0
                 trx_query: NULL
       trx_operation_state: NULL
         trx_tables_in_use: 0
         trx_tables_locked: 1
          trx_lock_structs: 1
     trx_lock_memory_bytes: 1136
           trx_rows_locked: 0
         trx_rows_modified: 17856929
   trx_concurrency_tickets: 0
       trx_isolation_level: REPEATABLE READ
         trx_unique_checks: 1
    trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
 trx_adaptive_hash_latched: 0
 trx_adaptive_hash_timeout: 0
          trx_is_read_only: 0
trx_autocommit_non_locking: 0

Is it possible to stop this transaction being rolled back?

How to repeat:
Cannot provide instruction on how this can be recreated elsewhere.
[17 Nov 2017 16:40] Sinisa Milivojevic
Hi!

Thank you for your bug report. However, most likely, this is not a bug. We had so many situations like this one and in vast majority of cases it turned out that some transaction was waiting on the end user's input, or on the long running statement, some network (or any other) resource or similar. This is because read / write transactions are practically holding many locks , until it is committed or rolled back.

If you want to see what is a culprit for the locks being held, when you notice a wait longer then 5 minutes run:

SHOW ENGINE INNODB STATUS;

and you will see which connection is holding the locks. Then you should determine what is that transaction actually waiting on. A connection can be in the "Sleep" state, in which case it is a problem of the application, which made transaction duration dependant on the end user's input.
[18 Dec 2017 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[25 Aug 2018 22:41] Miguel Solorzano
https://bugs.mysql.com/bug.php?id=92193 marked as duplicate of this one.
[26 Aug 2018 3:45] Arpan Roy
At first issue was observed once in 2 or 3 days. Last day, Issue observed 4 times in 5 hours. Why the sudden increase ? Any thoughts ? Was any solution provided for this issue so it will not recur ?
[27 Aug 2018 3:23] Arpan Roy
Should I reinstall MySQL?
[27 Aug 2018 12:07] Sinisa Milivojevic
No need to reinstall anything. You just need to use InnoDB status output and see which transaction and which connection is holding locks. Then, you should examine your application and see what is it waiting on.
[26 Sep 2018 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[8 Apr 8:10] Miguel Solorzano
https://bugs.mysql.com/bug.php?id=94930 marked as duplicate of this one.