View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0000572 | MySQL v5 for OS/2 & eComStation | Bug | public | 2013-04-23 00:13 | 2022-05-24 18:38 |
Reporter | asavage | Assigned To | psmedley | ||
Priority | high | Severity | crash | Reproducibility | always |
Status | closed | Resolution | fixed | ||
Platform | x86 | OS | WSA | OS Version | 3.0 with updates |
Summary | 0000572: mysqld dies silently | ||||
Description | v5.1.72 (was v5.1.68) After some period of uptime, varying from an hour to a day, mysqld dies with nothing logged to the console or error log. Console replay: ========================================================= [F:\mysql51]cd bin [F:\mysql51\bin]MySQLd.exe --basedir=F:\MySQL51 --datadir=F:\MySQL51\data --log-error --default-storage-engine=MyISAM --skip-innodb TlsAllocThreadLocalMemory error: init already done! [F:\mysql51\bin] ========================================================= Contents of error log after above: ========================================================= 130422 10:12:15 [Note] Plugin 'InnoDB' is disabled. 130422 10:12:15 [Note] Event Scheduler: Loaded 0 events 130422 10:12:15 [Note] MySQLd.exe: ready for connections. Version: '5.1.68' socket: '\socket\MySQL' port: 3306 Source distribution UNIX Socket is \socket\MySQL ========================================================= | ||||
Steps To Reproduce | See above. | ||||
Additional Information | With no more information coming from the module or log, I do not know how to proceed with this. SUT is Warp Server Advanced with HPFS386, kernel is 14.104a_W4, processor is old Athlon 1Ghz, 1Mb RAM. It is not a generally highly-loaded system, but it is in production, FWIW. I can probably run mysqld on another box and point the server to the alternate box, if necessary. | ||||
Tags | No tags attached. | ||||
Attached Files | PDUMP.001.txt (5,731 bytes)
IBM OS/2 Dump Formatter for a retail or an hstrict UNI kernel. Formatter is --> Internal revision 14.106_W4 Dump file is --> Internal revision 14.106_W4 (process dump) Symbol (d:\devtools\pmdf\14_106_w4_slamain\os2krnlr.sym) linked Current slot number: 00ca Slot Pid Ppid Csid Ord Sta Pri pTSD pPTDA pTCB Disp SG Name *00ca# 2320 231f 2320 0001 blk 0300 f995c000 f9d5d600 f9cb7ec0 0eb4 13 MYSQLD eax=00000000 ebx=0000efc0 ecx=00eb0053 edx=00000000 esi=00e7f68c edi=297a0000 eip=1ffca259 esp=00ebeb38 ebp=00ebec64 iopl=2 -- -- -- nv up ei pl nz ac po cy cs=005b ss=0053 ds=0053 es=0053 fs=150b gs=0000 cr2=00000000 cr3=00000000 005b:1ffca259 83c410 add esp,+10 # .p Slot Pid Ppid Csid Ord Sta Pri pTSD pPTDA pTCB Disp SG Name *00ca# 2320 231f 2320 0001 blk 0300 f995c000 f9d5d600 f9cb7ec0 0eb4 13 MYSQLD 0061 2320 231f 2320 0002 run 0300 f98f3000 f9d5d600 f9ca48ac 0af8 13 MYSQLD Slot 61 (i.e. ord 2) should have exited by the time the main thread complained # Checking call gates for all slots Slot MYSQLD 61: is in a call to: %1ffc6eac DOSCALL1 DOS32DUMPPROCESS Slot MYSQLD ca: is in a call to: %1ffc6f5c DOSCALL1 DOS32EXCEPTIONCALLBACK # %findsym esp l1000 Finding from 00ebeb38 to 00ebfb38 EBEC68: 1ffca692 = DOS32UNWINDEXCEPTION + 5a EBECA4: 1ffca2aa = _xcptExecuteUserExceptionHandler + 46 EBECA8: 1ffc1b27 = DOS32UNSETEXCEPTIONHANDLER + 3b EBECB0: 1ffca2c9 = _xcptExecuteUserExceptionHandler + 65 EBECC4: 1ffca2ec = _xcptR3ExceptionHandler EBECE0: 1ffc9f56 = _xcptR3ExceptionDispatcher + 10e EBED18: 1ffc9e26 = DOS32R3EXCEPTIONDISPATCHER + 12e EBED30: 1ffc9e26 = DOS32R3EXCEPTIONDISPATCHER + 12e EBED4C: 1fb965d2 = CharRect32 + 5be EBED80: 1ffc1b27 = DOS32UNSETEXCEPTIONHANDLER + 3b EBED84: 1cd49a5c = ulAvioFontMaxHeight + 40 EBED88: 1fc230f9 = PRF32QUERYPROFILESTRING + 1ad EBED9C: 1fbacd30 = ShlExceptionHandler EBEDB4: 1fc22f72 = PRF32QUERYPROFILESTRING + 26 EBEE80: fff52c04 = _vmFreeMemCtxtOd + 404 EBEEC0: fff53643 = _VMFreeMemOd + 2a3 EBEEC4: ffed0004 = _BufHashTable + 788 EBEEE8: fff6d314 = _VMFreeMem + 164 EBEF40: 1fb9ef4c = AlwaysSBCS Invalid address type: 409 - 0053:00ebf000 Scan stopped at EBFB39 stopaddr EBFB38 # %k EBEC68-4 00ebec64: Frame 00ebed2c Ret DOS32UNWINDEXCEPTION + 5a 00ebed2c: Frame 00ebee4c Ret DOS32R3EXCEPTIONDISPATCHER + 12e 00ebee4c: Frame 00e7f67c Ret 00000000 00e7f67c: Frame 00e7f69c Ret __exit + 37 00e7f69c: Frame 00e7f6bc Ret _exit + f 00e7f6bc: Frame 00e7f71c Ret _handle_fatal_signal + 21e 00e7f71c: Frame 00e7f7fc Ret __libc_back_signalRaiseInternal + e0c 00e7f7fc: Frame 00e7f88c Ret __libc_Back_signalRaise + 147 00e7f88c: Frame 00e7f90c Ret _libc_Back_exceptionHandler + 103 00e7f90c: Frame 00e7f93c Ret _xcptExecuteUserExceptionHandler + 46 00e7f93c: Frame 00e7f99c Ret _xcptR3ExceptionDispatcher + 88 00e7f99c: Frame 00e7fab8 Ret DOS32R3EXCEPTIONDISPATCHER + 5c 00e7fab8: Frame 00e7fc48 Ret 00000000 00e7fc48: Frame 00e7fe78 Ret _my_end + 47 00e7fe78: Frame 00e7ff80 Ret main + 9d8 00e7ff80: Frame 00e7ffe0 Ret __text + 21 00e7ffe0: Frame 00000000 Ret __init_app + b Can not access 0 - giving up # %xcpt Exception report record at 0328fbd8 ExceptNum c0010002 fHandlerFags 00000000 NestedExceptionReportRecord 00000000 ExceptionAddress 1d0eefa3 cParameters 00000001 P0 00000001 Context record at 0328fbfc ctxflags 00000007 eax 0000005f ebx 0328fd40 ecx 00000000 edx 00010009 edi 00000000 esi 00007530 esp 0328fd2c ebp 0328fd54 ss 00000053 eip 1d0eefa3 cs 0000005b gs 00000000 fs 0000150b es 00000053 ds 00000053 eflags 00002246 Exception registration record at 0328ff94 prev ffffffff handler 17441270 Found 1 report records on stack # .s61 (thread that did not exit) Current slot number: 0061 # %findsym esp l1000 Finding from 0328f9f0 to 032909f0 328FA1C: 1ffca2aa = _xcptExecuteUserExceptionHandler + 46 328FA3C: 1ffca2ec = _xcptR3ExceptionHandler 328FA4C: 1ffc9ed0 = _xcptR3ExceptionDispatcher + 88 328FA60: 1ffca2ec = _xcptR3ExceptionHandler 328FA88: 1d0cacf2 = _um_lump_alloc + 30a 328FA9C: 1ffc77c1 = HT32_Exit + 5 328FAAC: 1ffc9d54 = DOS32R3EXCEPTIONDISPATCHER + 5c 328FAF4: fff53643 = _VMFreeMemOd + 2a3 328FAF8: ffed0004 = _BufHashTable + 788 328FB1C: fff6d314 = _VMFreeMem + 164 328FB60: 1d0eefa3 = __libc_back_signalWait + be 328FB78: 1d0eab1a = __libc_Back_ioFileOpen + 356 328FBE4: 1d0eefa3 = __libc_back_signalWait + be 328FC2C: fff53643 = _VMFreeMemOd + 2a3 328FC30: ffed0004 = _BufHashTable + 788 328FC54: fff6d314 = _VMFreeMem + 164 328FC98: 1d0eefa3 = __libc_back_signalWait + be 328FCF8: 1d14e280 = __libc_Back_safesemMtxUnlock + 38 328FD28: 1d0eefa3 = __libc_back_signalWait + be 328FD58: 1d0f013e = __libc_Back_signalWait + 17e 328FE08: 1d11c5cd = _std_sigtimedwait + 1d 328FE18: 1d126cee = _um_free_maybe_lock + b2 328FE2C: 1ffc5df9 = DOS32WRITE + 29 328FE38: 1d14dcf4 = __libc_Back_safesemMtxLock + 54 328FE48: 1d14e280 = __libc_Back_safesemMtxUnlock + 38 328FE58: 1d0c8573 = __fmutex_release_internal_must_complete + 33 328FE78: 1d0ef254 = __libc_back_signalSemRelease + 10 328FE7C: 18fdcf68 = __libc_gSignalPending + 438 328FE98: 1d11c6d7 = _std_sigwait + 27 328FF98: 17441270 = MYHANDLER 328FFB8: 1d0f9dd3 = _endthread + 7f 328FFD8: 1d106550 = _libc_Back_exceptionHandler Scan stopped at 3290A00 stopaddr 32909F0 # %k 328FB60-4 0328fb5c: Frame 0328fd54 Ret __libc_back_signalWait + be 0328fd54: Frame 0328fe04 Ret __libc_Back_signalWait + 17e 0328fe04: Frame 0328fe94 Ret _std_sigtimedwait + 1d 0328fe94: Frame 0328ff04 Ret _std_sigwait + 27 0328ff04: Frame 0328ff64 Ret _signal_hand + 197 0328ff64: Frame 0328ffb4 Ret _pthread_exit + 25b 0328ffb4: Frame 0328fff4 Ret _endthread + 7f 0328fff4: Frame 00000000 Ret 1ffec188 Can not access 0 - giving up | ||||
|
I suspect the latest build may address this. I found a stack corruption bug in GCC which is addressed in GCC 4.7.3 |
|
Please provide feedback |
|
i've the same issue, nothing in popupos2.log, nothing in syslog, no dump, no exceptQ dump apache 2.2.25 + php 5.3.27 + mysql 5.1.72 massimo |
|
almost impossible to debug this without some kind of error |
|
Update: Testing with 5.1.72 https://dl.dropboxusercontent.com/u/76425158/mysql-5.1.72-os2-20130925.zip overlayed with these: http://www.os2site.com/sw/apps/database/mysql/mysqld-5.1.72-20131124.zip The system trapped several times. I am attaching the last TRP file, error log, and general log. httpd 1.3.41 PHP 4.3.10 |
|
today it exited with no paricular error or no dump: 140129 2:29:01 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 216 user: 'edc' 140129 2:29:01 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 213 user: 'edc' 140129 2:29:01 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 211 user: 'edc' 140129 2:29:01 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 166 user: 'edc' 140129 2:29:01 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 53 u ser: 'edc' 140129 2:29:01 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 44 u ser: 'edc' 140129 2:29:02 InnoDB: Starting shutdown... 140129 2:29:07 InnoDB: Shutdown completed; log sequence number 0 501341152 140129 2:29:07 [Note] X:\mysql\bin\mysqld.exe: Shutdown complete |
|
5.1.68 died last night. Attaching TRP, gen log, err log. Now with Oct2013 version of exceptq. |
|
I have annotated the .trp file and uploaded it as http://mantis.smedley.id.au/file_download.php?file_id=319&type=bug. To see the code flow that caused the shutdown, scan the Stack Contents dump and find the "frame" references. It appears that something occurred on the browser side that caused the the socket connection between mysql.dll, the PHP mysql extension, and mysqld.exe to close. This caused kLIBC to raise the SOCPIPE signal. However, mysqld does not define a handler for this signal, so kLIBC kills mysqld with a DosExit. The mysqld code says my_sigset(SIGPIPE,SIG_IGN); so something must be making it revert to its default setting. |
|
yup, like the fact that init_signals had an os2 specific implementation in the code I got from Yuri some years ago. Rebuilding now using the *nix code |
|
http://smedley.id.au/tmp/mysqld-5.1.72-20140131.zip Uses the unix code for init_signals. One (current) side effect of this is that ctrl-c won't kill mysqld |
|
Can I get a .map (or better, an .xqs) for this drop? |
|
zip updated with the xqs file |
|
it exit unexpectly even with this latest build http://smedley.id.au/tmp/mysqld-5.1.72-20140131.zip what i get to the window output (of course i don't get the first page since it scroll down): 140202 2:28:26 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 756 user: 'edc' 140202 2:28:26 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 676 user: 'edc' 140202 2:28:27 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 669 user: 'edc' 140202 2:28:27 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 661 user: 'edc' 140202 2:28:27 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 612 user: 'edc' 140202 2:28:27 [Warning] X:\mysql\bin\mysqld.exe: Forcing close of thread 578 user: 'edc' 140202 2:28:27 InnoDB: Starting shutdown... 140202 2:28:28 InnoDB: Shutdown completed; log sequence number 0 501344971 140202 2:28:28 [Note] X:\mysql\bin\mysqld.exe: Shutdown complete Error in my_thread_global_end(): 2 threads didn't exit [X:\mysql\bin] massimo |
|
Massimo, Where is the .trp file? Recall that you need to use the "Z" so that Process Termination Notices generate .trp files. The messages look like typical warnings. |
|
On an otherwise idle system, I see Error in my_thread_global_end(): 1 threads didn't exit It might be useful to know which thread(s) is/are not dieing. The easiest way to see what's going on is probably by forcing an exception after printing the message near mysys\my_thr_init.c:200 if an env variable exists. Something like if (getenv("DIEDIEDIE")) *(char *)0 = 0; should be sufficient. |
|
http://smedley.id.au/tmp/mysqld-20140205.zip has this change |
|
Looking at the process dump, we have thread 2 stuck at # %k 328FB60-4 0328fb5c: Frame 0328fd54 Ret __libc_back_signalWait + be 0328fd54: Frame 0328fe04 Ret __libc_Back_signalWait + 17e 0328fe04: Frame 0328fe94 Ret _std_sigtimedwait + 1d 0328fe94: Frame 0328ff04 Ret _std_sigwait + 27 0328ff04: Frame 0328ff64 Ret _signal_hand + 197 0328ff64: Frame 0328ffb4 Ret _pthread_exit + 25b 0328ffb4: Frame 0328fff4 Ret _endthread + 7f 0328fff4: Frame 00000000 Ret 1ffec188 Can not access 0 - giving up It appears that signal_hand() is waiting for a signal that never comes or possibly the signal came before cleanup_done was set. |
|
Error in my_thread_global_end(): 1 threads didn't exit goes away using the standard unix code in mysqld.cc - however with that, mysqladmin -u username shutdown fails Will try do some more digging on the weekend |
|
http://smedley.id.au/tmp/mysqld-20140209.zip Back to using the os2 branch for init_signals, but added: my_sigset(SIGPIPE,SIG_IGN); from the unix version of init_signals |
|
I've got it installed, and will monitor the logs to see if aberrant stuff happens. |
|
http://smedley.id.au/tmp/mysqld-20140209.zip allow mysqladmin to do a clean shutdown. A Ctrl-C shutdown still results in Error in my_thread_global_end(): 1 threads didn't exit here, but I believe the error is mostly cosmetic. |
|
Running that last drop (20140209), it's run nine days uninterrupted without dying, which is a lot better than I'd seen previously. Due to other issues (EVFS), I've had to reboot the box a few times, but when left alone mysqld seems to be working well. |
|
when i close mysql (i restart it each night) i allways see a high number of threads even if i've no connections in that moment i suspect mysql do not close correctly some connection from PHP (call to the db via mysql php module) this happens with all versions of mysqlD this one and previous ones massimo |
|
Max, that issue should be reported in a separate bug report. Is mysqld unexpectedly stopping for you? |
|
with latest version i've no more strange/unexpected exit |
Date Modified | Username | Field | Change |
---|---|---|---|
2013-04-23 00:13 | asavage | New Issue | |
2013-10-10 23:03 | psmedley | Note Added: 0002544 | |
2013-10-11 11:03 | psmedley | Note Added: 0002559 | |
2013-10-11 11:03 | psmedley | Assigned To | => psmedley |
2013-10-11 11:03 | psmedley | Status | new => feedback |
2014-01-24 20:04 | emax | Note Added: 0002644 | |
2014-01-24 20:04 | emax | Note Edited: 0002644 | |
2014-01-24 20:17 | psmedley | Note Added: 0002645 | |
2014-01-29 02:29 | asavage | Note Added: 0002648 | |
2014-01-29 02:29 | asavage | Status | feedback => assigned |
2014-01-29 02:31 | asavage | File Added: 0087_04.TRP | |
2014-01-29 02:32 | asavage | File Added: Joni2-err-20140125-1830.log | |
2014-01-29 02:38 | asavage | File Added: Joni2-gen-20140125-1830-snipped.log | |
2014-01-29 10:05 | emax | Note Added: 0002649 | |
2014-01-31 02:28 | asavage | Note Added: 0002653 | |
2014-01-31 02:33 | asavage | File Added: Joni2-gen-20140126-1651-snipped.log | |
2014-01-31 02:34 | asavage | File Added: Joni2-err-20140126-1651.log | |
2014-01-31 02:35 | asavage | File Added: 007A_06.TRP | |
2014-01-31 03:42 | Steven Levine | File Added: 007A_06-shl-annotated.TRP | |
2014-01-31 04:05 | Steven Levine | Note Added: 0002654 | |
2014-01-31 08:46 | psmedley | Note Added: 0002655 | |
2014-01-31 08:58 | psmedley | Note Added: 0002656 | |
2014-01-31 20:46 | asavage | Note Added: 0002657 | |
2014-01-31 21:41 | psmedley | Note Added: 0002658 | |
2014-02-02 15:38 | emax | Note Added: 0002661 | |
2014-02-05 01:07 | Steven Levine | Description Updated | |
2014-02-05 01:10 | Steven Levine | Note Added: 0002663 | |
2014-02-05 01:10 | Steven Levine | Status | assigned => feedback |
2014-02-05 01:47 | Steven Levine | Note Added: 0002664 | |
2014-02-05 08:51 | psmedley | Note Added: 0002665 | |
2014-02-05 23:31 | Steven Levine | Note Added: 0002666 | |
2014-02-05 23:32 | Steven Levine | File Added: PDUMP.001.txt | |
2014-02-06 08:53 | psmedley | Note Added: 0002667 | |
2014-02-08 23:51 | psmedley | Note Added: 0002668 | |
2014-02-09 02:31 | asavage | Note Added: 0002669 | |
2014-02-09 02:31 | asavage | Status | feedback => assigned |
2014-02-09 07:45 | Steven Levine | Note Added: 0002670 | |
2014-03-09 00:07 | asavage | Note Added: 0002683 | |
2014-03-10 08:27 | emax | Note Added: 0002686 | |
2014-03-10 14:29 | asavage | Note Added: 0002688 | |
2014-03-10 14:32 | emax | Note Added: 0002689 | |
2014-04-03 06:46 | psmedley | Status | assigned => resolved |
2014-04-03 06:46 | psmedley | Resolution | open => fixed |
2020-08-24 03:09 | psmedley | Status | resolved => closed |