Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-34546

No errorlog entries after startup in XAMPP

Details

    • Bug
    • Status: Closed (View Workflow)
    • Critical
    • Resolution: Fixed
    • 10.4.28, 10.5
    • 10.5.26
    • Platform Windows
    • None
    • Windows, XAMPP

    Description

      Currently, my MariaDB hangs or crashes after any query. The mysql_error.log file (attached the tail) is not helpful, but after a crash many files are created in the xampp/mysql/data directory with names containing some information. I see a message failing assertion is_dblwr_recover and a message to report the bug here.

      Edit: after deleting multi-master.info file multi-master.info everything seems to work normally. I have added this file causing the crash.

      Attachments

        1. aria_log_control
          0.1 kB
        2. dir after crash.txt
          27 kB
        3. ib_buffer_pool
          0.8 kB
        4. multi-master.info
          4 kB
        5. mysql_error.log.part
          18 kB

        Issue Links

          Activity

            wlad Vladislav Vaintroub added a comment - - edited

            I can reproduce the following

            After startup, there are no more entries in the error log, that is, neither warning nor [Note] will go there. Seems like a bad and undocumented interaction with FreeConsole() API, which makes redirected stdout not to work anymore, after it is called.

            The messages go nowhere, I debugged C runtime a bit, the underlying WriteFile keeps telling "invalid handle".

            Before that, procmon shows error log file handle to error log being closed (NtClose), with following stack

            here 10.5 current

            0	FLTMGR.SYS	FltGetStreamContext + 0x20cb	0xfffff80075ee963b	C:\WINDOWS\System32\drivers\FLTMGR.SYS
            1	FLTMGR.SYS	FltGetStreamContext + 0x1b51	0xfffff80075ee90c1	C:\WINDOWS\System32\drivers\FLTMGR.SYS
            2	FLTMGR.SYS	FltGetStreamContext + 0xad9	0xfffff80075ee8049	C:\WINDOWS\System32\drivers\FLTMGR.SYS
            3	FLTMGR.SYS	FltGetStreamContext + 0x8bb	0xfffff80075ee7e2b	C:\WINDOWS\System32\drivers\FLTMGR.SYS
            4	ntoskrnl.exe	IofCallDriver + 0x55	0xfffff80079ec1ab5	C:\WINDOWS\system32\ntoskrnl.exe
            5	ntoskrnl.exe	SeQueryInformationToken + 0x170f	0xfffff8007a3be1ff	C:\WINDOWS\system32\ntoskrnl.exe
            6	ntoskrnl.exe	NtDeviceIoControlFile + 0x1163	0xfffff8007a3c5ba3	C:\WINDOWS\system32\ntoskrnl.exe
            7	ntoskrnl.exe	NtClose + 0x39	0xfffff8007a3c34a9	C:\WINDOWS\system32\ntoskrnl.exe
            8	ntoskrnl.exe	setjmpex + 0x90d5	0xfffff8007a02b405	C:\WINDOWS\system32\ntoskrnl.exe
            9	ntdll.dll	ZwClose + 0x14	0x7fff84d90184	C:\Windows\System32\ntdll.dll
            10	KernelBase.dll	FreeConsole + 0xd7	0x7fff8272ed07	C:\Windows\System32\KernelBase.dll
            11	KernelBase.dll	FreeConsole + 0x2c	0x7fff8272ec5c	C:\Windows\System32\KernelBase.dll
            12	server.dll	win_main + 0x530, E:\10.5\sql\mysqld.cc(5589)	0x7ffecfb676f0	E:\10.5\xxx\sql\Debug\server.dll
            13	server.dll	mysql_service + 0x4e, E:\10.5\sql\mysqld.cc(5829)	0x7ffecfb67cee	E:\10.5\xxx\sql\Debug\server.dll
            14	server.dll	mysqld_main + 0x54d, E:\10.5\sql\mysqld.cc(6050)	0x7ffecfb687ad	E:\10.5\xxx\sql\Debug\server.dll
            15	mariadbd.exe	main + 0x1c, E:\10.5\sql\main.cc(25)	0x7ff7faad26cc	E:\10.5\xxx\sql\Debug\mariadbd.exe
            16	mariadbd.exe	__scrt_common_main_seh + 0x10c, D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl(281)	0x7ff7faad2950	E:\10.5\xxx\sql\Debug\mariadbd.exe
            17	kernel32.dll	BaseThreadInitThunk + 0x1d	0x7fff83b6257d	C:\Windows\System32\kernel32.dll
            18	ntdll.dll	RtlUserThreadStart + 0x28	0x7fff84d4af28	C:\Windows\System32\ntdll.dll
            

            As far as I understand, this used to work OK, because we had seen error messages with (bad) XAMPP stacktraces in the past, but it is something new in Windows, that makes it misbehave now.

            Even the end of startup is missing, the lines like

            2024-07-10 13:01:05 0 [Note] c:\xampp\mysql\bin\mysqld.exe: ready for connections.
            Version: '10.4.32-MariaDB'  socket: ''  port: 3306  Source distribution
            

            are not shown anymore.

            I can't reproduce writing to master-info but I can imagine that it could happen in some circumstances.

            Apparently, disappearing stdout only happens if the console window with mysqld.exe is gone, so was never caught in the internal testing, where mysqld would share the console with mtr.

            So I see it in XAMPP, or I can reproduce it when starting mysqld.exe from cmd.exe with "start mysqld.exe" (forces

            Good news : this does not happen if you run as service, this does not happen if you run with --console parameter, and this does not happen in 10.6+, where FreeConsole() is gone

            Bad news (for Treinfan: there won't be fixes for 10.4 anymore, but XAMPP does not care and continues to use 10.4 even after its EOL.

            I can fix it for 10.5 (only)
            The trick I tried is to call FreeConsole() right before out/err redirection, not after it.

            wlad Vladislav Vaintroub added a comment - - edited I can reproduce the following After startup, there are no more entries in the error log, that is, neither warning nor [Note] will go there. Seems like a bad and undocumented interaction with FreeConsole() API, which makes redirected stdout not to work anymore, after it is called. The messages go nowhere, I debugged C runtime a bit, the underlying WriteFile keeps telling "invalid handle". Before that, procmon shows error log file handle to error log being closed (NtClose), with following stack here 10.5 current 0 FLTMGR.SYS FltGetStreamContext + 0x20cb 0xfffff80075ee963b C:\WINDOWS\System32\drivers\FLTMGR.SYS 1 FLTMGR.SYS FltGetStreamContext + 0x1b51 0xfffff80075ee90c1 C:\WINDOWS\System32\drivers\FLTMGR.SYS 2 FLTMGR.SYS FltGetStreamContext + 0xad9 0xfffff80075ee8049 C:\WINDOWS\System32\drivers\FLTMGR.SYS 3 FLTMGR.SYS FltGetStreamContext + 0x8bb 0xfffff80075ee7e2b C:\WINDOWS\System32\drivers\FLTMGR.SYS 4 ntoskrnl.exe IofCallDriver + 0x55 0xfffff80079ec1ab5 C:\WINDOWS\system32\ntoskrnl.exe 5 ntoskrnl.exe SeQueryInformationToken + 0x170f 0xfffff8007a3be1ff C:\WINDOWS\system32\ntoskrnl.exe 6 ntoskrnl.exe NtDeviceIoControlFile + 0x1163 0xfffff8007a3c5ba3 C:\WINDOWS\system32\ntoskrnl.exe 7 ntoskrnl.exe NtClose + 0x39 0xfffff8007a3c34a9 C:\WINDOWS\system32\ntoskrnl.exe 8 ntoskrnl.exe setjmpex + 0x90d5 0xfffff8007a02b405 C:\WINDOWS\system32\ntoskrnl.exe 9 ntdll.dll ZwClose + 0x14 0x7fff84d90184 C:\Windows\System32\ntdll.dll 10 KernelBase.dll FreeConsole + 0xd7 0x7fff8272ed07 C:\Windows\System32\KernelBase.dll 11 KernelBase.dll FreeConsole + 0x2c 0x7fff8272ec5c C:\Windows\System32\KernelBase.dll 12 server.dll win_main + 0x530, E:\10.5\sql\mysqld.cc(5589) 0x7ffecfb676f0 E:\10.5\xxx\sql\Debug\server.dll 13 server.dll mysql_service + 0x4e, E:\10.5\sql\mysqld.cc(5829) 0x7ffecfb67cee E:\10.5\xxx\sql\Debug\server.dll 14 server.dll mysqld_main + 0x54d, E:\10.5\sql\mysqld.cc(6050) 0x7ffecfb687ad E:\10.5\xxx\sql\Debug\server.dll 15 mariadbd.exe main + 0x1c, E:\10.5\sql\main.cc(25) 0x7ff7faad26cc E:\10.5\xxx\sql\Debug\mariadbd.exe 16 mariadbd.exe __scrt_common_main_seh + 0x10c, D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl(281) 0x7ff7faad2950 E:\10.5\xxx\sql\Debug\mariadbd.exe 17 kernel32.dll BaseThreadInitThunk + 0x1d 0x7fff83b6257d C:\Windows\System32\kernel32.dll 18 ntdll.dll RtlUserThreadStart + 0x28 0x7fff84d4af28 C:\Windows\System32\ntdll.dll As far as I understand, this used to work OK, because we had seen error messages with (bad) XAMPP stacktraces in the past, but it is something new in Windows, that makes it misbehave now. Even the end of startup is missing, the lines like 2024-07-10 13:01:05 0 [Note] c:\xampp\mysql\bin\mysqld.exe: ready for connections. Version: '10.4.32-MariaDB' socket: '' port: 3306 Source distribution are not shown anymore. I can't reproduce writing to master-info but I can imagine that it could happen in some circumstances. Apparently, disappearing stdout only happens if the console window with mysqld.exe is gone, so was never caught in the internal testing, where mysqld would share the console with mtr. So I see it in XAMPP, or I can reproduce it when starting mysqld.exe from cmd.exe with "start mysqld.exe" (forces Good news : this does not happen if you run as service, this does not happen if you run with --console parameter, and this does not happen in 10.6+, where FreeConsole() is gone Bad news (for Treinfan : there won't be fixes for 10.4 anymore, but XAMPP does not care and continues to use 10.4 even after its EOL. I can fix it for 10.5 (only) The trick I tried is to call FreeConsole() right before out/err redirection, not after it.
            wlad Vladislav Vaintroub added a comment - - edited

            Apparently, some people report the weird FreeConsole behavior back in Windows 8. Strange it was not noticed here.
            UPD: I myself noticed something in MDEV-23783, but did not hear of anyone else back then, and thought of it as debugger interaction problems.

            wlad Vladislav Vaintroub added a comment - - edited Apparently, some people report the weird FreeConsole behavior back in Windows 8. Strange it was not noticed here. UPD: I myself noticed something in MDEV-23783 , but did not hear of anyone else back then, and thought of it as debugger interaction problems.

            It looks like the error in multi-master.info was not filed as a bug:

            mariadb-10.4.28

            Version: '10.4.28-MariaDB'  socket: ''  port: 3306  mariadb.org binary distribution
            2024-07-08 21:45:11 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
            2024-07-08 21:45:11 0 [ERROR] InnoDB: Write to file C:\xampp\mysql\data\ib_logfile0 failed at offset 2048, 512 bytes should have been written, only 0 were written. Operating system error number 0. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
            2024-07-08 21:45:11 0x26ac  InnoDB: Assertion failure in file D:\winx64-packages\build\src\storage\innobase\fil\fil0fil.cc line 4287
            InnoDB: Failing assertion: req_type.is_dblwr_recover() || err == DB_SUCCESS
            

            It looks like there was some error when trying to write the InnoDB write-ahead log file. The log writing was simplified in MariaDB Server 10.5 and further in later major versions such as 10.6 and 10.11. If such an error occurs in 10.6 or later, I’d like to see a bug report for it. The diagnostics was changed for this:

                ib::fatal() << "write(" << fd.get_path() << ") returned " << err
                            << ". Operating system error number "
                            << IF_WIN(GetLastError(), errno) << ".";
            

            The message that precedes the intentional crash should be something like the following:

            [ERROR] [FATAL] write(C:\xampp\mysql\data\ib_logfile0) returned …
            

            marko Marko Mäkelä added a comment - It looks like the error in multi-master.info was not filed as a bug: mariadb-10.4.28 Version: '10.4.28-MariaDB' socket: '' port: 3306 mariadb.org binary distribution 2024-07-08 21:45:11 0 [Warning] InnoDB: Retry attempts for writing partial data failed. 2024-07-08 21:45:11 0 [ERROR] InnoDB: Write to file C:\xampp\mysql\data\ib_logfile0 failed at offset 2048, 512 bytes should have been written, only 0 were written. Operating system error number 0. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded. 2024-07-08 21:45:11 0x26ac InnoDB: Assertion failure in file D:\winx64-packages\build\src\storage\innobase\fil\fil0fil.cc line 4287 InnoDB: Failing assertion: req_type.is_dblwr_recover() || err == DB_SUCCESS It looks like there was some error when trying to write the InnoDB write-ahead log file. The log writing was simplified in MariaDB Server 10.5 and further in later major versions such as 10.6 and 10.11. If such an error occurs in 10.6 or later, I’d like to see a bug report for it. The diagnostics was changed for this: ib::fatal() << "write(" << fd.get_path() << ") returned " << err << ". Operating system error number " << IF_WIN(GetLastError(), errno ) << "." ; The message that precedes the intentional crash should be something like the following: [ERROR] [FATAL] write(C:\xampp\mysql\data\ib_logfile0) returned …

            People

              wlad Vladislav Vaintroub
              Treinfan Rens
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.