tech.guitarrapc.cóm

Technical updates

SQL Server Docker Image のCU12以降でDBがクラッシュする件

SQL Serverは Dockerで動かせるので、いちいちSQL Server をインストールせずともローカル開発をスムーズに回すことができます。

hub.docker.com

そんな SQL Server on Docker ですが、macOS ではホストのDBファイルをボリュームマウントができない制約があります。

Mounting a volume does not work on Docker for Mac

一方で、Windows ではホストのDBファイルをボリュームマウントできるため永続化させたいときとかに便利です。

さて、今回の記事はWindows環境でホストのDBをコンテナでマウントするとクラッシュする件が起こっていることについてです。

目次

TL;DR

CU12*1 以降でホストのDBファイルをボリュームマウントで渡していると、SQL Serverがクラッシュします。

latest でも発生しており、ホストのDBをボリュームマウントする場合は、CU11 に落とすのが暫定対処になりそう。

Issue

CU 12 で問題は発覚しました。

github.com

CU13以降、現在の latest では、このCU13 のクラッシュログが確認できます。

github.com

再現してみよう

とりあえず手元で再現すれば逃げ道も見つかります。試しましょう。

2017-latest (2017-latest-ubuntu)

現在の最新イメージでホストのボリュームをマウントしない場合は、SQL Server が起動できていることがわかります。

docker run -it -e ACCEPT_EULA=Y mcr.microsoft.com/mssql/server:2017-latest

ログを開く

2019-04-26 03:07:27.52 Server      Setup step is copying system data file 'C:\templatedata\master.mdf' to '/var/opt/mssql/data/master.mdf'.
2019-04-26 03:07:27.56 Server      Did not find an existing master data file /var/opt/mssql/data/master.mdf, copying the missing default master and other system database files. If you have moved the database location, but not moved the database files, startup may fail. To repair: shutdown SQL Server, move the master database to configured location, and restart.
2019-04-26 03:07:27.56 Server      Setup step is copying system data file 'C:\templatedata\mastlog.ldf' to '/var/opt/mssql/data/mastlog.ldf'.
2019-04-26 03:07:27.57 Server      Setup step is copying system data file 'C:\templatedata\model.mdf' to '/var/opt/mssql/data/model.mdf'.
2019-04-26 03:07:27.58 Server      Setup step is copying system data file 'C:\templatedata\modellog.ldf' to '/var/opt/mssql/data/modellog.ldf'.
2019-04-26 03:07:27.59 Server      Setup step is copying system data file 'C:\templatedata\msdbdata.mdf' to '/var/opt/mssql/data/msdbdata.mdf'.
2019-04-26 03:07:27.61 Server      Setup step is copying system data file 'C:\templatedata\msdblog.ldf' to '/var/opt/mssql/data/msdblog.ldf'.
2019-04-26 03:07:27.68 Server      Microsoft SQL Server 2017 (RTM-CU14) (KB4484710) - 14.0.3076.1 (X64)
        Mar 12 2019 19:29:19
        Copyright (C) 2017 Microsoft Corporation
        Developer Edition (64-bit) on Linux (Ubuntu 16.04.6 LTS)
2019-04-26 03:07:27.68 Server      UTC adjustment: 0:00
2019-04-26 03:07:27.68 Server      (c) Microsoft Corporation.
2019-04-26 03:07:27.68 Server      All rights reserved.
2019-04-26 03:07:27.68 Server      Server process ID is 28.
2019-04-26 03:07:27.69 Server      Logging SQL Server messages in file '/var/opt/mssql/log/errorlog'.
2019-04-26 03:07:27.69 Server      Registry startup parameters:
         -d /var/opt/mssql/data/master.mdf
         -l /var/opt/mssql/data/mastlog.ldf
         -e /var/opt/mssql/log/errorlog
2019-04-26 03:07:27.69 Server      SQL Server detected 1 sockets with 1 cores per socket and 2 logical processors per socket, 2 total logical processors; using 2 logical processors based on SQL Server licensing. This is an informational message; no user action is required.
2019-04-26 03:07:27.69 Server      SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
2019-04-26 03:07:27.70 Server      Detected 1584 MB of RAM. This is an informational message; no user action is required.
2019-04-26 03:07:27.70 Server      Using conventional memory in the memory manager.
2019-04-26 03:07:27.84 Server      Buffer pool extension is already disabled. No action is necessary.
2019-04-26 03:07:27.94 Server      InitializeExternalUserGroupSid failed. Implied authentication will be disabled.
2019-04-26 03:07:27.94 Server      Implied authentication manager initialization failed. Implied authentication will be disabled.
2019-04-26 03:07:27.94 Server      Successfully initialized the TLS configuration. Allowed TLS protocol versions are ['1.0 1.1 1.2']. Allowed TLS ciphers are ['ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:!DHE-RSA-AES256-GCM-SHA384:!DHE-RSA-AES128-GCM-SHA256:!DHE-RSA-AES256-SHA:!DHE-RSA-AES128-SHA'].
2019-04-26 03:07:27.98 Server      The maximum number of dedicated administrator connections for this instance is '1'
2019-04-26 03:07:27.98 Server      Node configuration: node 0: CPU mask: 0x0000000000000003:0 Active CPU mask: 0x0000000000000003:0. This message provides a description of the NUMA configuration for this computer. This is an
informational message only. No user action is required.
2019-04-26 03:07:27.99 Server      Using dynamic lock allocation.  Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node.  This is an informational message only.  No user action is required.
2019-04-26 03:07:27.99 Server      In-Memory OLTP initialized on lowend machine.
2019-04-26 03:07:28.02 Server      Database Instant File Initialization: enabled. For security and performance considerations see the topic 'Database Instant File Initialization' in SQL Server Books Online. This is an informational message only. No user action is required.
ForceFlush is enabled for this instance.
2019-04-26 03:07:28.03 Server      Query Store settings initialized with enabled = 1,
2019-04-26 03:07:28.03 Server      Software Usage Metrics is disabled.
2019-04-26 03:07:28.04 spid6s      Starting up database 'master'.
ForceFlush feature is enabled for log durability.
2019-04-26 03:07:28.16 spid6s      The tail of the log for database master is being rewritten to match the new sector size of 4096 bytes.  3072 bytes at offset 418816 in file /var/opt/mssql/data/mastlog.ldf will be written.
2019-04-26 03:07:28.27 spid6s      Converting database 'master' from version 862 to the current version 869.
2019-04-26 03:07:28.27 spid6s      Database 'master' running the upgrade step from version 862 to version 863.
2019-04-26 03:07:28.30 spid6s      Database 'master' running the upgrade step from version 863 to version 864.
2019-04-26 03:07:28.33 spid6s      Database 'master' running the upgrade step from version 864 to version 865.
2019-04-26 03:07:28.35 spid6s      Database 'master' running the upgrade step from version 865 to version 866.
2019-04-26 03:07:28.36 spid6s      Database 'master' running the upgrade step from version 866 to version 867.
2019-04-26 03:07:28.37 spid6s      Database 'master' running the upgrade step from version 867 to version 868.
2019-04-26 03:07:28.38 spid6s      Database 'master' running the upgrade step from version 868 to version 869.
2019-04-26 03:07:28.47 Server      Failed to verify the Authenticode signature of 'C:\binn\secforwarder.dll'. Signature verification of SQL Server DLLs will be skipped. Genuine copies of SQL Server are signed. Failure to verify the Authenticode signature might indicate that this is not an authentic release of SQL Server. Install a genuine copy of SQL Server or contact customer support.
2019-04-26 03:07:28.58 spid6s      Resource governor reconfiguration succeeded.
2019-04-26 03:07:28.58 spid6s      SQL Server Audit is starting the audits. This is an informational message. No user action is required.
2019-04-26 03:07:28.59 spid6s      SQL Server Audit has started the audits. This is an informational message. No user action is required.
2019-04-26 03:07:28.62 spid6s      SQL Trace ID 1 was started by login "sa".
2019-04-26 03:07:28.64 spid6s      Server name is '4200ec551fc5'. This is an informational message only. No user action is required.
2019-04-26 03:07:28.65 spid19s     Password policy update was successful.
2019-04-26 03:07:28.66 spid22s     Always On: The availability replica manager is starting. This is an informational message only. No user action is required.
2019-04-26 03:07:28.66 spid6s      Starting up database 'msdb'.
2019-04-26 03:07:28.67 spid22s     Always On: The availability replica manager is waiting for the instance of SQL Server to allow client connections. This is an informational message only. No user action is required.
2019-04-26 03:07:28.67 spid11s     Starting up database 'mssqlsystemresource'.
2019-04-26 03:07:28.67 spid11s     The resource database build version is 14.00.3076. This is an informational message only. No user action is required.
2019-04-26 03:07:28.70 spid11s     Starting up database 'model'.
2019-04-26 03:07:28.85 spid19s     A self-generated certificate was successfully loaded for encryption.
2019-04-26 03:07:28.86 spid19s     Server is listening on [ 'any' <ipv6> 1433].
2019-04-26 03:07:28.86 spid19s     Server is listening on [ 'any' <ipv4> 1433].
2019-04-26 03:07:28.86 spid11s     The tail of the log for database model is being rewritten to match the new sector size of 4096 bytes.  2048 bytes at offset 75776 in file /var/opt/mssql/data/modellog.ldf will be written.
2019-04-26 03:07:28.87 Server      Server is listening on [ ::1 <ipv6> 1434].
2019-04-26 03:07:28.87 Server      Server is listening on [ 127.0.0.1 <ipv4> 1434].
2019-04-26 03:07:28.87 Server      Dedicated admin connection support was established for listening locally on port 1434.
2019-04-26 03:07:28.87 spid19s     SQL Server is now ready for client connections. This is an informational message; no user action is required.
2019-04-26 03:07:28.87 spid6s      The tail of the log for database msdb is being rewritten to match the new sector size of 4096 bytes.  512 bytes at offset 306688 in file /var/opt/mssql/data/MSDBLog.ldf will be written.
2019-04-26 03:07:28.99 spid11s     Converting database 'model' from version 862 to the current version 869.
2019-04-26 03:07:28.99 spid11s     Database 'model' running the upgrade step from version 862 to version 863.
2019-04-26 03:07:29.00 spid6s      Converting database 'msdb' from version 862 to the current version 869.
2019-04-26 03:07:29.00 spid6s      Database 'msdb' running the upgrade step from version 862 to version 863.
2019-04-26 03:07:29.06 spid11s     Database 'model' running the upgrade step from version 863 to version 864.
2019-04-26 03:07:29.10 spid6s      Database 'msdb' running the upgrade step from version 863 to version 864.
2019-04-26 03:07:29.10 spid11s     Database 'model' running the upgrade step from version 864 to version 865.
2019-04-26 03:07:29.12 spid11s     Database 'model' running the upgrade step from version 865 to version 866.
2019-04-26 03:07:29.12 spid6s      Database 'msdb' running the upgrade step from version 864 to version 865.
2019-04-26 03:07:29.13 spid11s     Database 'model' running the upgrade step from version 866 to version 867.
2019-04-26 03:07:29.13 spid6s      Database 'msdb' running the upgrade step from version 865 to version 866.
2019-04-26 03:07:29.14 spid11s     Database 'model' running the upgrade step from version 867 to version 868.
2019-04-26 03:07:29.15 spid6s      Database 'msdb' running the upgrade step from version 866 to version 867.
2019-04-26 03:07:29.16 spid6s      Database 'msdb' running the upgrade step from version 867 to version 868.
2019-04-26 03:07:29.16 spid11s     Database 'model' running the upgrade step from version 868 to version 869.
2019-04-26 03:07:29.17 spid6s      Database 'msdb' running the upgrade step from version 868 to version 869.
2019-04-26 03:07:29.29 spid11s     Polybase feature disabled.
2019-04-26 03:07:29.29 spid11s     Clearing tempdb database.
2019-04-26 03:07:29.63 spid11s     Starting up database 'tempdb'.
2019-04-26 03:07:29.82 spid11s     The tempdb database has 1 data file(s).
2019-04-26 03:07:29.83 spid22s     The Service Broker endpoint is in disabled or stopped state.
2019-04-26 03:07:29.83 spid22s     The Database Mirroring endpoint is in disabled or stopped state.
2019-04-26 03:07:29.84 spid22s     Service Broker manager has started.
2019-04-26 03:07:29.96 spid6s      Recovery is complete. This is an informational message only. No user action is required.
2019-04-26 03:07:29.98 spid24s     The default language (LCID 0) has been set for engine and full-text services.
2019-04-26 03:07:33.03 spid35s     The activated proc '[dbo].[sp_syspolicy_events_reader]' running on queue 'msdb.dbo.syspolicy_event_queue' output the following:  'Transaction (Process ID 35) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction

では、適当にフォルダを掘ってからDBフォルダにマウントしましょう。

mkdir c:\db
docker run -it -e ACCEPT_EULA=Y -v C:\db:/var/opt/mssql mcr.microsoft.com/mssql/server:2017-latest-ubuntu

見事にクラッシュしています。

This program has encountered a fatal error and cannot continue running at Fri Apr 26 03:14:04 2019
The following diagnostic information is available:

       Reason: 0x00000006
       Status: 0x40000015
      Message: Kernel bug check
      Address: 0x6a844180
   Parameters: 0x10861f680
   Stacktrace: 000000006a92fc73 000000006a8441db 000000006a831422
               000000006a83fe62 000000006a92e08a 000000006a92cb8d
               000000006a96c0d2 000000006acac000 000000006ac38000
               000000006ac40000 0000000000000001
      Process: 7 - sqlservr
       Thread: 11 (application thread 0x4)
  Instance Id: 72388ba8-dd88-4469-b1fe-c4794d04ff54
     Crash Id: 3593f479-5b4f-4ef6-ad74-b70a3bda2756
  Build stamp: b2ce95e3a6684060d1d3bb1264841a1a8fc1d501ed6d1cfdb89cfcdde8048253
 Distribution: Ubuntu 16.04.6 LTS
   Processors: 2
 Total Memory: 2076528640 bytes
    Timestamp: Fri Apr 26 03:14:04 2019

Ubuntu 16.04.6 LTS
Capturing core dump and information to /var/opt/mssql/log...
dmesg: read kernel buffer failed: Operation not permitted
No journal files were found.
No journal files were found.
Attempting to capture a dump with paldumper
WARNING: Capture attempt failure detected
Attempting to capture a filtered dump with paldumper
WARNING: Attempt to capture dump failed.  Reference /var/opt/mssql/log/core.sqlservr.7.temp/log/paldumper-debug.log for details
Attempting to capture a dump with gdb
WARNING: Unable to capture crash dump with GDB. You may need to
allow ptrace debugging, enable the CAP_SYS_PTRACE capability, or
run as root.

クラッシュログ置いておきます。

crash.txt

This program has encountered a fatal error and cannot continue running at Fri Apr 26 03:40:08 2019
The following diagnostic information is available:

       Reason: 0x00000006
       Status: 0x40000015
      Message: Kernel bug check
      Address: 0x6c244180
   Parameters: 0x10861f680
   Stacktrace: 000000006c32fc73 000000006c2441db 000000006c231422 
               000000006c23fe62 000000006c32e08a 000000006c32cb8d 
               000000006c36c0d2 000000006c6ac000 000000006c638000 
               000000006c640000 0000000000000001 
      Process: 7 - sqlservr
       Thread: 11 (application thread 0x4)
  Instance Id: e467da02-a594-4124-93cb-c8eb2415c65a
     Crash Id: e751eea3-120c-448b-92c5-dc0b370c783d
  Build stamp: b2ce95e3a6684060d1d3bb1264841a1a8fc1d501ed6d1cfdb89cfcdde8048253
 Distribution: Ubuntu 16.04.6 LTS
   Processors: 2
 Total Memory: 2076528640 bytes
    Timestamp: Fri Apr 26 03:40:08 2019

crash.json

{
    "reason": "0x00000006",
    "processName": "sqlservr",
    "pid": "7",
    "instanceId": "e467da02-a594-4124-93cb-c8eb2415c65a",
    "crashId": "e751eea3-120c-448b-92c5-dc0b370c783d",
    "threadId": "11",
    "libosThreadId": "0x4",
    "buildStamp": "b2ce95e3a6684060d1d3bb1264841a1a8fc1d501ed6d1cfdb89cfcdde8048253",
    "status": "0x40000015",
    "message": "Kernel bug check",
    "address": "0x6c244180",
    "parameters": [
        {
            "value": "0x41"
        },
        {
            "value": "0xffffffffc0000034"
        },
        {
            "value": "0x5"
        },
        {
            "value": "0x0"
        },
        {
            "value": "0x0"
        }
    ],
    "libosStack": [
        "0x000000006c32fc73",
        "0x000000006c2441db",
        "0x000000006c231422",
        "0x000000006c23fe62",
        "0x000000006c32e08a",
        "0x000000006c32cb8d",
        "0x000000006c36c0d2",
        "0x000000006c6ac000",
        "0x000000006c638000",
        "0x000000006c640000",
        "0x0000000000000001"
    ],
    "last_errno": "2",
    "last_errno_text": "No such file or directory",
    "distribution": "Ubuntu 16.04.6 LTS",
    "processors": "2",
    "total_memory": "2076528640",
    "timestamp": "Fri Apr 26 03:40:08 2019"
}

No such file or directory.....

2017-CU11-ubuntu

CU11 まで落とすとマウントできています。

mkdir c:\db
docker run -it -e ACCEPT_EULA=Y -v C:\db:/var/opt/mssql mcr.microsoft.com/mssql/server:2017-CU11-ubuntu

ログを開く

2019-04-26 03:18:07.29 Server      Setup step is copying system data file 'C:\templatedata\master.mdf' to '/var/opt/mssql/data/master.mdf'.
2019-04-26 03:18:08.13 Server      Did not find an existing master data file /var/opt/mssql/data/master.mdf, copying the missing default master and other system database files. If you have moved the database location, but not moved the database files, startup may fail. To repair: shutdown SQL Server, move the master database to configured location, and restart.
2019-04-26 03:18:08.15 Server      Setup step is copying system data file 'C:\templatedata\mastlog.ldf' to '/var/opt/mssql/data/mastlog.ldf'.
2019-04-26 03:18:08.19 Server      Setup step is copying system data file 'C:\templatedata\model.mdf' to '/var/opt/mssql/data/model.mdf'.
2019-04-26 03:18:08.34 Server      Setup step is copying system data file 'C:\templatedata\modellog.ldf' to '/var/opt/mssql/data/modellog.ldf'.
2019-04-26 03:18:08.49 Server      Setup step is copying system data file 'C:\templatedata\msdbdata.mdf' to '/var/opt/mssql/data/msdbdata.mdf'.
2019-04-26 03:18:08.69 Server      Setup step is copying system data file 'C:\templatedata\msdblog.ldf' to '/var/opt/mssql/data/msdblog.ldf'.
2019-04-26 03:18:09.69 Server      Microsoft SQL Server 2017 (RTM-CU11) (KB4462262) - 14.0.3038.14 (X64)
        Sep 14 2018 13:53:44
        Copyright (C) 2017 Microsoft Corporation
        Developer Edition (64-bit) on Linux (Ubuntu 16.04.5 LTS)
2019-04-26 03:18:09.70 Server      UTC adjustment: 0:00
2019-04-26 03:18:09.70 Server      (c) Microsoft Corporation.
2019-04-26 03:18:09.70 Server      All rights reserved.
2019-04-26 03:18:09.70 Server      Server process ID is 4120.
2019-04-26 03:18:09.70 Server      Logging SQL Server messages in file '/var/opt/mssql/log/errorlog'.
2019-04-26 03:18:09.70 Server      Registry startup parameters:
         -d /var/opt/mssql/data/master.mdf
         -l /var/opt/mssql/data/mastlog.ldf
         -e /var/opt/mssql/log/errorlog
2019-04-26 03:18:09.72 Server      SQL Server detected 1 sockets with 1 cores per socket and 2 logical processors per socket, 2 total logical processors; using 2 logical processors based on SQL Server licensing. This is an informational message; no user action is required.
2019-04-26 03:18:09.72 Server      SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
2019-04-26 03:18:09.72 Server      Detected 1584 MB of RAM. This is an informational message; no user action is required.
2019-04-26 03:18:09.72 Server      Using conventional memory in the memory manager.
2019-04-26 03:18:12.56 Server      Buffer pool extension is already disabled. No action is necessary.
2019-04-26 03:18:13.80 Server      InitializeExternalUserGroupSid failed. Implied authentication will be disabled.
2019-04-26 03:18:13.80 Server      Implied authentication manager initialization failed. Implied authentication will be disabled.
2019-04-26 03:18:13.81 Server      Successfully initialized the TLS configuration. Allowed TLS protocol versions are ['1.0 1.1 1.2']. Allowed TLS ciphers are ['ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:!DHE-RSA-AES256-GCM-SHA384:!DHE-RSA-AES128-GCM-SHA256:!DHE-RSA-AES256-SHA:!DHE-RSA-AES128-SHA'].
2019-04-26 03:18:13.98 Server      Node configuration: node 0: CPU mask: 0x0000000000000003:0 Active CPU mask: 0x0000000000000003:0. This message provides a description of the NUMA configuration for this computer. This is an
informational message only. No user action is required.
2019-04-26 03:18:13.99 Server      The maximum number of dedicated administrator connections for this instance is '1'
2019-04-26 03:18:13.99 Server      Using dynamic lock allocation.  Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node.  This is an informational message only.  No user action is required.
2019-04-26 03:18:13.99 Server      In-Memory OLTP initialized on lowend machine.
2019-04-26 03:18:14.24 Server      Database Instant File Initialization: enabled. For security and performance considerations see the topic 'Database Instant File Initialization' in SQL Server Books Online. This is an informational message only. No user action is required.
ForceFlush is enabled for this instance.
2019-04-26 03:18:14.24 Server      Query Store settings initialized with enabled = 1,
2019-04-26 03:18:14.25 spid6s      Starting up database 'master'.
2019-04-26 03:18:14.28 Server      Software Usage Metrics is disabled.
ForceFlush feature is enabled for log durability.
2019-04-26 03:18:15.76 spid6s      The tail of the log for database master is being rewritten to match the new sector size of 4096 bytes.  3072 bytes at offset 418816 in file /var/opt/mssql/data/mastlog.ldf will be written.
2019-04-26 03:18:16.63 spid6s      Converting database 'master' from version 862 to the current version 869.
2019-04-26 03:18:16.63 spid6s      Database 'master' running the upgrade step from version 862 to version 863.
2019-04-26 03:18:16.65 spid6s      Database 'master' running the upgrade step from version 863 to version 864.
2019-04-26 03:18:16.82 spid6s      Database 'master' running the upgrade step from version 864 to version 865.
2019-04-26 03:18:16.84 spid6s      Database 'master' running the upgrade step from version 865 to version 866.
2019-04-26 03:18:16.85 spid6s      Database 'master' running the upgrade step from version 866 to version 867.
2019-04-26 03:18:16.85 spid6s      Database 'master' running the upgrade step from version 867 to version 868.
2019-04-26 03:18:16.87 spid6s      Database 'master' running the upgrade step from version 868 to version 869.
2019-04-26 03:18:18.14 spid6s      Resource governor reconfiguration succeeded.
2019-04-26 03:18:18.14 spid6s      SQL Server Audit is starting the audits. This is an informational message. No user action is required.
2019-04-26 03:18:18.14 spid6s      SQL Server Audit has started the audits. This is an informational message. No user action is required.
2019-04-26 03:18:18.47 spid6s      SQL Trace ID 1 was started by login "sa".
2019-04-26 03:18:18.48 spid18s     Password policy update was successful.
2019-04-26 03:18:18.49 spid6s      Server name is 'f16aca2a7c35'. This is an informational message only. No user action is required.
2019-04-26 03:18:18.49 spid21s     Always On: The availability replica manager is starting. This is an informational message only. No user action is required.
2019-04-26 03:18:18.50 spid21s     Always On: The availability replica manager is waiting for the instance of SQL Server to allow client connections. This is an informational message only. No user action is required.
2019-04-26 03:18:18.50 spid8s      Starting up database 'mssqlsystemresource'.
2019-04-26 03:18:18.50 spid6s      Starting up database 'msdb'.
2019-04-26 03:18:18.51 spid8s      The resource database build version is 14.00.3038. This is an informational message only. No user action is required.
2019-04-26 03:18:18.53 spid8s      Starting up database 'model'.
2019-04-26 03:18:20.73 spid6s      The tail of the log for database msdb is being rewritten to match the new sector size of 4096 bytes.  512 bytes at offset 306688 in file /var/opt/mssql/data/MSDBLog.ldf will be written.
2019-04-26 03:18:20.77 spid6s      Converting database 'msdb' from version 862 to the current version 869.
2019-04-26 03:18:20.77 spid6s      Database 'msdb' running the upgrade step from version 862 to version 863.
2019-04-26 03:18:20.78 spid8s      The tail of the log for database model is being rewritten to match the new sector size of 4096 bytes.  2048 bytes at offset 75776 in file /var/opt/mssql/data/modellog.ldf will be written.
2019-04-26 03:18:20.81 spid8s      Converting database 'model' from version 862 to the current version 869.
2019-04-26 03:18:20.81 spid8s      Database 'model' running the upgrade step from version 862 to version 863.
2019-04-26 03:18:20.82 spid6s      Database 'msdb' running the upgrade step from version 863 to version 864.
2019-04-26 03:18:20.84 spid8s      Database 'model' running the upgrade step from version 863 to version 864.
2019-04-26 03:18:20.84 spid6s      Database 'msdb' running the upgrade step from version 864 to version 865.
2019-04-26 03:18:20.86 spid6s      Database 'msdb' running the upgrade step from version 865 to version 866.
2019-04-26 03:18:20.86 spid8s      Database 'model' running the upgrade step from version 864 to version 865.
2019-04-26 03:18:20.87 spid6s      Database 'msdb' running the upgrade step from version 866 to version 867.
2019-04-26 03:18:20.87 spid8s      Database 'model' running the upgrade step from version 865 to version 866.
2019-04-26 03:18:20.88 spid8s      Database 'model' running the upgrade step from version 866 to version 867.
2019-04-26 03:18:20.88 spid6s      Database 'msdb' running the upgrade step from version 867 to version 868.
2019-04-26 03:18:20.90 spid8s      Database 'model' running the upgrade step from version 867 to version 868.
2019-04-26 03:18:20.90 spid6s      Database 'msdb' running the upgrade step from version 868 to version 869.
2019-04-26 03:18:20.92 spid8s      Database 'model' running the upgrade step from version 868 to version 869.
2019-04-26 03:18:21.05 spid8s      Polybase feature disabled.
2019-04-26 03:18:21.05 spid8s      Clearing tempdb database.
2019-04-26 03:18:24.70 spid18s     A self-generated certificate was successfully loaded for encryption.
2019-04-26 03:18:24.73 spid18s     Server is listening on [ 'any' <ipv4> 1433].
2019-04-26 03:18:24.74 Server      Server is listening on [ 127.0.0.1 <ipv4> 1434].
2019-04-26 03:18:24.74 Server      Dedicated admin connection support was established for listening locally on port 1434.
2019-04-26 03:18:24.75 spid18s     SQL Server is now ready for client connections. This is an informational message; no user action is required.
2019-04-26 03:18:25.93 spid8s      Starting up database 'tempdb'.
2019-04-26 03:18:27.55 spid8s      The tempdb database has 1 data file(s).
2019-04-26 03:18:27.55 spid21s     The Service Broker endpoint is in disabled or stopped state.
2019-04-26 03:18:27.56 spid21s     The Database Mirroring endpoint is in disabled or stopped state.
2019-04-26 03:18:27.57 spid21s     Service Broker manager has started.
2019-04-26 03:18:27.68 spid6s      Recovery is complete. This is an informational message only. No user action is required.
2019-04-26 03:18:33.21 spid10s     The default language (LCID 0) has been set for engine and full-text services.

対処方法

CU11 まで落とすと、問題は発生しません。 Microsoftの反応がないので、どうするのか悩ましいですがいったんCU11 で固定しておくとよさそうです。

余談

自分でDockerfile 書いてSQL Server (Linux) をインストールして利用という手もあります。

が、試しに CU12 のイメージをもとにDockerfile を書くと面白いログが出ています。(CU12+ からapt-get で sql-server を入れてないため)

The following additional packages will be installed:

mssql-server

gist.github.com

どんな対応がいいのかしらの反応が待ち遠しいですね。

エラーログ

おいておきます。

2019-04-26 03:18:09.69 Server      Microsoft SQL Server 2017 (RTM-CU11) (KB4462262) - 14.0.3038.14 (X64) 
    Sep 14 2018 13:53:44 
    Copyright (C) 2017 Microsoft Corporation
    Developer Edition (64-bit) on Linux (Ubuntu 16.04.5 LTS)
2019-04-26 03:18:09.70 Server      UTC adjustment: 0:00
2019-04-26 03:18:09.70 Server      (c) Microsoft Corporation.
2019-04-26 03:18:09.70 Server      All rights reserved.
2019-04-26 03:18:09.70 Server      Server process ID is 4120.
2019-04-26 03:18:09.70 Server      Logging SQL Server messages in file '/var/opt/mssql/log/errorlog'.
2019-04-26 03:18:09.70 Server      Registry startup parameters: 
     -d /var/opt/mssql/data/master.mdf
     -l /var/opt/mssql/data/mastlog.ldf
     -e /var/opt/mssql/log/errorlog
2019-04-26 03:18:09.72 Server      SQL Server detected 1 sockets with 1 cores per socket and 2 logical processors per socket, 2 total logical processors; using 2 logical processors based on SQL Server licensing. This is an informational message; no user action is required.
2019-04-26 03:18:09.72 Server      SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
2019-04-26 03:18:09.72 Server      Detected 1584 MB of RAM. This is an informational message; no user action is required.
2019-04-26 03:18:09.72 Server      Using conventional memory in the memory manager.
2019-04-26 03:18:12.56 Server      Buffer pool extension is already disabled. No action is necessary. 
2019-04-26 03:18:13.80 Server      InitializeExternalUserGroupSid failed. Implied authentication will be disabled.
2019-04-26 03:18:13.80 Server      Implied authentication manager initialization failed. Implied authentication will be disabled.
2019-04-26 03:18:13.81 Server      Successfully initialized the TLS configuration. Allowed TLS protocol versions are ['1.0 1.1 1.2']. Allowed TLS ciphers are ['ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:!DHE-RSA-AES256-GCM-SHA384:!DHE-RSA-AES128-GCM-SHA256:!DHE-RSA-AES256-SHA:!DHE-RSA-AES128-SHA'].
2019-04-26 03:18:13.98 Server      Node configuration: node 0: CPU mask: 0x0000000000000003:0 Active CPU mask: 0x0000000000000003:0. This message provides a description of the NUMA configuration for this computer. This is an informational message only. No user action is required.
2019-04-26 03:18:13.99 Server      The maximum number of dedicated administrator connections for this instance is '1'
2019-04-26 03:18:13.99 Server      Using dynamic lock allocation.  Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node.  This is an informational message only.  No user action is required.
2019-04-26 03:18:13.99 Server      In-Memory OLTP initialized on lowend machine.
2019-04-26 03:18:14.24 Server      Database Instant File Initialization: enabled. For security and performance considerations see the topic 'Database Instant File Initialization' in SQL Server Books Online. This is an informational message only. No user action is required.
2019-04-26 03:18:14.25 spid6s      Starting up database 'master'.
2019-04-26 03:18:14.24 Server      Query Store settings initialized with enabled = 1, 
2019-04-26 03:18:14.28 Server      Software Usage Metrics is disabled.
2019-04-26 03:18:15.76 spid6s      The tail of the log for database master is being rewritten to match the new sector size of 4096 bytes.  3072 bytes at offset 418816 in file /var/opt/mssql/data/mastlog.ldf will be written.
2019-04-26 03:18:16.63 spid6s      Converting database 'master' from version 862 to the current version 869.
2019-04-26 03:18:16.63 spid6s      Database 'master' running the upgrade step from version 862 to version 863.
2019-04-26 03:18:16.65 spid6s      Database 'master' running the upgrade step from version 863 to version 864.
2019-04-26 03:18:16.82 spid6s      Database 'master' running the upgrade step from version 864 to version 865.
2019-04-26 03:18:16.84 spid6s      Database 'master' running the upgrade step from version 865 to version 866.
2019-04-26 03:18:16.85 spid6s      Database 'master' running the upgrade step from version 866 to version 867.
2019-04-26 03:18:16.85 spid6s      Database 'master' running the upgrade step from version 867 to version 868.
2019-04-26 03:18:16.87 spid6s      Database 'master' running the upgrade step from version 868 to version 869.
2019-04-26 03:18:18.14 spid6s      Resource governor reconfiguration succeeded.
2019-04-26 03:18:18.14 spid6s      SQL Server Audit is starting the audits. This is an informational message. No user action is required.
2019-04-26 03:18:18.14 spid6s      SQL Server Audit has started the audits. This is an informational message. No user action is required.
2019-04-26 03:18:18.47 spid6s      SQL Trace ID 1 was started by login "sa".
2019-04-26 03:18:18.48 spid18s     Password policy update was successful.
2019-04-26 03:18:18.49 spid6s      Server name is 'f16aca2a7c35'. This is an informational message only. No user action is required.
2019-04-26 03:18:18.49 spid21s     Always On: The availability replica manager is starting. This is an informational message only. No user action is required.
2019-04-26 03:18:18.50 spid21s     Always On: The availability replica manager is waiting for the instance of SQL Server to allow client connections. This is an informational message only. No user action is required.
2019-04-26 03:18:18.50 spid8s      Starting up database 'mssqlsystemresource'.
2019-04-26 03:18:18.50 spid6s      Starting up database 'msdb'.
2019-04-26 03:18:18.51 spid8s      The resource database build version is 14.00.3038. This is an informational message only. No user action is required.
2019-04-26 03:18:18.53 spid8s      Starting up database 'model'.
2019-04-26 03:18:20.73 spid6s      The tail of the log for database msdb is being rewritten to match the new sector size of 4096 bytes.  512 bytes at offset 306688 in file /var/opt/mssql/data/MSDBLog.ldf will be written.
2019-04-26 03:18:20.77 spid6s      Converting database 'msdb' from version 862 to the current version 869.
2019-04-26 03:18:20.77 spid6s      Database 'msdb' running the upgrade step from version 862 to version 863.
2019-04-26 03:18:20.78 spid8s      The tail of the log for database model is being rewritten to match the new sector size of 4096 bytes.  2048 bytes at offset 75776 in file /var/opt/mssql/data/modellog.ldf will be written.
2019-04-26 03:18:20.81 spid8s      Converting database 'model' from version 862 to the current version 869.
2019-04-26 03:18:20.81 spid8s      Database 'model' running the upgrade step from version 862 to version 863.
2019-04-26 03:18:20.82 spid6s      Database 'msdb' running the upgrade step from version 863 to version 864.
2019-04-26 03:18:20.84 spid8s      Database 'model' running the upgrade step from version 863 to version 864.
2019-04-26 03:18:20.84 spid6s      Database 'msdb' running the upgrade step from version 864 to version 865.
2019-04-26 03:18:20.86 spid6s      Database 'msdb' running the upgrade step from version 865 to version 866.
2019-04-26 03:18:20.86 spid8s      Database 'model' running the upgrade step from version 864 to version 865.
2019-04-26 03:18:20.87 spid6s      Database 'msdb' running the upgrade step from version 866 to version 867.
2019-04-26 03:18:20.87 spid8s      Database 'model' running the upgrade step from version 865 to version 866.
2019-04-26 03:18:20.88 spid8s      Database 'model' running the upgrade step from version 866 to version 867.
2019-04-26 03:18:20.88 spid6s      Database 'msdb' running the upgrade step from version 867 to version 868.
2019-04-26 03:18:20.90 spid8s      Database 'model' running the upgrade step from version 867 to version 868.
2019-04-26 03:18:20.90 spid6s      Database 'msdb' running the upgrade step from version 868 to version 869.
2019-04-26 03:18:20.92 spid8s      Database 'model' running the upgrade step from version 868 to version 869.
2019-04-26 03:18:21.05 spid8s      Polybase feature disabled.
2019-04-26 03:18:21.05 spid8s      Clearing tempdb database.
2019-04-26 03:18:24.70 spid18s     A self-generated certificate was successfully loaded for encryption.
2019-04-26 03:18:24.73 spid18s     Server is listening on [ 'any' <ipv4> 1433].
2019-04-26 03:18:24.74 Server      Server is listening on [ 127.0.0.1 <ipv4> 1434].
2019-04-26 03:18:24.74 Server      Dedicated admin connection support was established for listening locally on port 1434.
2019-04-26 03:18:24.75 spid18s     SQL Server is now ready for client connections. This is an informational message; no user action is required.
2019-04-26 03:18:25.93 spid8s      Starting up database 'tempdb'.
2019-04-26 03:18:27.55 spid8s      The tempdb database has 1 data file(s).
2019-04-26 03:18:27.55 spid21s     The Service Broker endpoint is in disabled or stopped state.
2019-04-26 03:18:27.56 spid21s     The Database Mirroring endpoint is in disabled or stopped state.
2019-04-26 03:18:27.57 spid21s     Service Broker manager has started.
2019-04-26 03:18:27.68 spid6s      Recovery is complete. This is an informational message only. No user action is required.
2019-04-26 03:18:33.21 spid10s     The default language (LCID 0) has been set for engine and full-text services.
2019-04-26 03:20:54.61 spid6s      Always On: The availability replica manager is going offline because SQL Server is shutting down. This is an informational message only. No user action is required.
2019-04-26 03:20:54.61 spid6s      SQL Server shutdown due to Ctrl-C or Ctrl-Break signal. This is an informational message only. No user action is required.
2019-04-26 03:20:54.61 spid6s      SQL Trace was stopped due to server shutdown. Trace ID = '1'. This is an informational message only; no user action is required.

*1:CU = Cumulative Update - a periodic release that includes bug fixes, security fixes, and occasionally a small feature.