LocalDb: Database creation is failing on the hosted Azure DevOps build agent

Description

Tests fail on the Azure DevOps hosted build agent with VS2019 (windows-2019) because the database creation fails due to missing log files.

Using LocalDb to get a blank db for each test with the following base class which xUnit.net test classes inherit from:

public class TestBase{

    static SqlInstance<CommunicationContext> instance;


    static TestBase()
    {
        instance = new SqlInstance<CommunicationContext>(
            constructInstance: builder => new CommunicationContext(builder.Options));
    }

    public Task<SqlDatabase<CommunicationContext>> LocalDb(
        string databaseSuffix = null,
        [CallerMemberName] string memberName = null)
    {
        return instance.Build(GetType().Name, databaseSuffix, memberName);
    }
}

Using the LocalDb like the examples:

            using (var database = await LocalDb())
            {
                // Generate entities
                ...cut for brevity...
            }

Everything runs fine locally. Both in VS2019 with the Test Explorer and from the command line running dotnet test or dotnet test --configuration release

When running the test on the Azure DevOps hosted build agent with VS2019 (windows-2019) the tests fail because the database creation fails.

Azure DevOps logs

The complete logfile can be seen here: https://gist.github.com/henriksen/e7562ff7018932d8d8dc62dc727970d4 The most relevant parts are repeated below

Output from dotnet test on the build server

2019-07-12T07:14:29.8313051Z ##[command]"C:\windows\system32\cmd.exe" /D /E:ON /V:OFF /S /C "CALL "d:\a\_temp\a11b0a2a-d31c-4089-985c-3ebc28d92fc9.cmd""
2019-07-12T07:14:31.4513307Z Build started, please wait...
2019-07-12T07:14:33.6194892Z Build completed.
2019-07-12T07:14:33.6196083Z 
2019-07-12T07:14:33.6221979Z Test run for D:\a\1\s\LocalDbRepo\bin\Debug\netcoreapp2.2\LocalDbRepo.dll(.NETCoreApp,Version=v2.2)
2019-07-12T07:14:33.9493992Z Microsoft (R) Test Execution Command Line Tool Version 15.9.0
2019-07-12T07:14:33.9495081Z Copyright (c) Microsoft Corporation.  All rights reserved.
2019-07-12T07:14:33.9495871Z 
2019-07-12T07:14:34.4629404Z Starting test execution, please wait...
2019-07-12T07:14:55.2637431Z [xUnit.net 00:00:18.99]     LocalDbRepo.Pipelines.GetConversationByIdHandlerTests.Handle_GivenInvalidConversationId_ThrowKeyNotFoundException [FAIL]
2019-07-12T07:14:55.3076292Z Failed   LocalDbRepo.Pipelines.GetConversationByIdHandlerTests.Handle_GivenInvalidConversationId_ThrowKeyNotFoundException
2019-07-12T07:14:55.3082063Z Error Message:
2019-07-12T07:14:55.3083234Z  System.Exception : Failed to ExecuteCommand
2019-07-12T07:14:55.3084984Z commandText: 
2019-07-12T07:14:55.3086090Z create database [GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException] on
2019-07-12T07:14:55.3087302Z (
2019-07-12T07:14:55.3088240Z     name = [GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException],
2019-07-12T07:14:55.3089120Z     filename = 'd:\a\_temp\LocalDb\CommunicationContext\GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException.mdf'
2019-07-12T07:14:55.3089830Z )
2019-07-12T07:14:55.3090362Z for attach;
2019-07-12T07:14:55.3090841Z 
2019-07-12T07:14:55.3091550Z alter database [GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException]
2019-07-12T07:14:55.3092257Z     modify file (name=template, newname='GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException')
2019-07-12T07:14:55.3093037Z alter database [GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException]
2019-07-12T07:14:55.3093948Z     modify file (name=template_log, newname='GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException_log')
2019-07-12T07:14:55.3094511Z 
2019-07-12T07:14:55.3095133Z connectionString: Data Source=(LocalDb)\CommunicationContext;Database=master
2019-07-12T07:14:55.3095658Z 
2019-07-12T07:14:55.3097175Z ---- System.Data.SqlClient.SqlException : Could not open new database 'GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException'. CREATE DATABASE is aborted.
2019-07-12T07:14:55.3097919Z Database 'GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException' does not exist. Make sure that the name is entered correctly.
2019-07-12T07:14:55.3098573Z File activation failure. The physical file name "d:\a\_temp\LocalDb\CommunicationContext\GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException_log.ldf" may be incorrect.
2019-07-12T07:14:55.3100291Z The log cannot be rebuilt when the primary file is read-only.
2019-07-12T07:14:55.3101235Z Stack Trace:
2019-07-12T07:14:55.3101848Z    at SqlExtensions.ExecuteCommandAsync(SqlConnection connection, String commandText) in C:\projects\localdb\src\LocalDb\SqlExtensions.cs:line 40
2019-07-12T07:14:55.3102993Z    at Wrapper.CreateDatabaseFromFile(String name, Task fileCopyTask) in C:\projects\localdb\src\LocalDb\Wrapper.cs:line 160
2019-07-12T07:14:55.3103531Z    at EfLocalDb.SqlInstance`1.Build(String dbName, IEnumerable`1 data) in C:\projects\localdb\src\EfLocalDb\SqlInstance.cs:line 233
2019-07-12T07:14:55.3104343Z    at LocalDbRepo.Pipelines.GetConversationByIdHandlerTests.Handle_GivenInvalidConversationId_ThrowKeyNotFoundException() in D:\a\1\s\LocalDbRepo\Pipelines\GetConversationByIdHandlerTests.cs:line 46
2019-07-12T07:14:55.3104995Z --- End of stack trace from previous location where exception was thrown ---
2019-07-12T07:14:55.3105859Z ----- Inner Stack Trace -----
2019-07-12T07:14:55.3107113Z    at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
2019-07-12T07:14:55.3107966Z    at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
2019-07-12T07:14:55.3108397Z    at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
2019-07-12T07:14:55.3108985Z    at System.Data.SqlClient.SqlCommand.EndExecuteNonQueryInternal(IAsyncResult asyncResult)
2019-07-12T07:14:55.3109477Z    at System.Data.SqlClient.SqlCommand.EndExecuteNonQuery(IAsyncResult asyncResult)
2019-07-12T07:14:55.3110553Z    at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
2019-07-12T07:14:55.3111564Z --- End of stack trace from previous location where exception was thrown ---
2019-07-12T07:14:55.3112388Z    at SqlExtensions.ExecuteCommandAsync(SqlConnection connection, String commandText) in C:\projects\localdb\src\LocalDb\SqlExtensions.cs:line 35
2019-07-12T07:14:55.3559749Z [xUnit.net 00:00:19.09]     LocalDbRepo.Pipelines.GetConversationByIdHandlerTests.Handle_GivenTwoConversations_SelectsJustTheOne [FAIL]
2019-07-12T07:14:55.4437665Z Failed   LocalDbRepo.Pipelines.GetConversationByIdHandlerTests.Handle_GivenTwoConversations_SelectsJustTheOne
2019-07-12T07:14:55.4438554Z Error Message:
2019-07-12T07:14:55.4439236Z  System.Exception : Failed to ExecuteCommand
2019-07-12T07:14:55.4439769Z commandText: 
2019-07-12T07:14:55.4441174Z create database [GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne] on
2019-07-12T07:14:55.4441623Z (
2019-07-12T07:14:55.4442070Z     name = [GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne],
2019-07-12T07:14:55.4442541Z     filename = 'd:\a\_temp\LocalDb\CommunicationContext\GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne.mdf'
2019-07-12T07:14:55.4443117Z )
2019-07-12T07:14:55.4443526Z for attach;
2019-07-12T07:14:55.4443969Z 
2019-07-12T07:14:55.4444392Z alter database [GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne]
2019-07-12T07:14:55.4444896Z     modify file (name=template, newname='GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne')
2019-07-12T07:14:55.4445374Z alter database [GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne]
2019-07-12T07:14:55.4445825Z     modify file (name=template_log, newname='GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne_log')
2019-07-12T07:14:55.4446943Z 
2019-07-12T07:14:55.4447519Z connectionString: Data Source=(LocalDb)\CommunicationContext;Database=master
2019-07-12T07:14:55.4447985Z 
2019-07-12T07:14:55.4448925Z ---- System.Data.SqlClient.SqlException : Could not open new database 'GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne'. CREATE DATABASE is aborted.
2019-07-12T07:14:55.4449566Z Database 'GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne' does not exist. Make sure that the name is entered correctly.
2019-07-12T07:14:55.4450361Z File activation failure. The physical file name "d:\a\_temp\LocalDb\CommunicationContext\GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne_log.ldf" may be incorrect.
2019-07-12T07:14:55.4450836Z The log cannot be rebuilt when the primary file is read-only.
2019-07-12T07:14:55.4451268Z Stack Trace:
2019-07-12T07:14:55.4451695Z    at SqlExtensions.ExecuteCommandAsync(SqlConnection connection, String commandText) in C:\projects\localdb\src\LocalDb\SqlExtensions.cs:line 40
2019-07-12T07:14:55.4452279Z    at Wrapper.CreateDatabaseFromFile(String name, Task fileCopyTask) in C:\projects\localdb\src\LocalDb\Wrapper.cs:line 160
2019-07-12T07:14:55.4452899Z    at EfLocalDb.SqlInstance`1.Build(String dbName, IEnumerable`1 data) in C:\projects\localdb\src\EfLocalDb\SqlInstance.cs:line 233
2019-07-12T07:14:55.4453541Z    at LocalDbRepo.Pipelines.GetConversationByIdHandlerTests.Handle_GivenTwoConversations_SelectsJustTheOne() in D:\a\1\s\LocalDbRepo\Pipelines\GetConversationByIdHandlerTests.cs:line 23
2019-07-12T07:14:55.4454379Z --- End of stack trace from previous location where exception was thrown ---
2019-07-12T07:14:55.4455980Z ----- Inner Stack Trace -----
2019-07-12T07:14:55.4459599Z    at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
2019-07-12T07:14:55.4460437Z    at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
2019-07-12T07:14:55.4461154Z    at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
2019-07-12T07:14:55.4461681Z    at System.Data.SqlClient.SqlCommand.EndExecuteNonQueryInternal(IAsyncResult asyncResult)
2019-07-12T07:14:55.4462287Z    at System.Data.SqlClient.SqlCommand.EndExecuteNonQuery(IAsyncResult asyncResult)
2019-07-12T07:14:55.4462765Z    at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
2019-07-12T07:14:55.4463267Z --- End of stack trace from previous location where exception was thrown ---
2019-07-12T07:14:55.4463762Z    at SqlExtensions.ExecuteCommandAsync(SqlConnection connection, String commandText) in C:\projects\localdb\src\LocalDb\SqlExtensions.cs:line 35
2019-07-12T07:14:55.4583687Z 
2019-07-12T07:14:55.4585107Z Test Run Failed.
2019-07-12T07:14:55.4585457Z Total tests: 2. Passed: 0. Failed: 2. Skipped: 0.
2019-07-12T07:14:55.4586279Z Test execution time: 20.8861 Seconds

Testing SqlLocalDb Creation

Trying to create a database with SqlLocalDb works fine:

SqlLocalDB c "GetConversationByIdHandlerTests_Handle_GivenConversationWithAssignedUser_IncludedAssignedUser"
SqlLocalDB s "GetConversationByIdHandlerTests_Handle_GivenConversationWithAssignedUser_IncludedAssignedUser"
SqlLocalDB v
SqlLocalDB trace on

yields

2019-07-12T07:14:06.2456096Z LocalDB instance "GetConversationByIdHandlerTests_Handle_GivenConversationWithAssignedUser_IncludedAssignedUser" created with version 13.1.4001.0.
2019-07-12T07:14:06.2457235Z 
2019-07-12T07:14:07.8730659Z LocalDB instance "GetConversationByIdHandlerTests_Handle_GivenConversationWithAssignedUser_IncludedAssignedUser" started.
2019-07-12T07:14:07.8732775Z 
2019-07-12T07:14:07.8917039Z Windows API call "RegGetValueW" returned error code: 0.
2019-07-12T07:14:07.8918311Z 
2019-07-12T07:14:07.9082783Z LocalDB Instance API tracing turned ON.

Database files left behind after test

Build agent

In the TEMP directory after the tests the test databases are missing their logfiles:

2019-07-12T07:14:55.5032803Z  Directory of d:\a\_temp\LocalDb\CommunicationContext
2019-07-12T07:14:55.5033223Z 
2019-07-12T07:14:55.5033727Z 07/12/2019  07:14 AM    <DIR>          .
2019-07-12T07:14:55.5034174Z 07/12/2019  07:14 AM    <DIR>          ..
2019-07-12T07:14:55.5034750Z 07/12/2019  07:14 AM         3,145,728 GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException.mdf
2019-07-12T07:14:55.5035316Z 07/12/2019  07:14 AM         3,145,728 GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne.mdf
2019-07-12T07:14:55.5035812Z 07/12/2019  07:14 AM         3,145,728 template.mdf
2019-07-12T07:14:55.5036186Z 07/12/2019  07:14 AM           524,288 template_log.ldf
2019-07-12T07:14:55.5037221Z                4 File(s)      9,961,472 bytes
2019-07-12T07:14:55.5037580Z                2 Dir(s)  13,057,638,400 bytes free

Locally

Running the tests locally leaves both the .mdf file and the .ldf file

> dir $env:temp\LocalDb\CommunicationContext

Mode                LastWriteTime     Length Name
----                -------------     ------ ----
-a----       12.07.2019     09:03     3,00MB GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException.mdf
-a----       12.07.2019     09:03   504,00KB GetConversationByIdHandlerTests_Handle_GivenInvalidConversationId_ThrowKeyNotFoundException_log.ldf
-a----       12.07.2019     09:03     3,00MB GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne.mdf
-a----       12.07.2019     09:03   504,00KB GetConversationByIdHandlerTests_Handle_GivenTwoConversations_SelectsJustTheOne_log.ldf
-a----       12.07.2019     09:03     3,00MB template.mdf
-a----       12.07.2019     09:03   512,00KB template_log.ldf

Minimal Repro

I’ve created a minimal repo here: https://github.com/henriksen/localDbRepo

Submit a PR that fixes the bug

Am going to try changing the create database script to include the .ldf file as well. Will update with a PR if that works out.

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 17 (6 by maintainers)

Most upvoted comments

btw if u still want to use the agent temp drive (which is faster) you can try running this ps script at startup

$paths = @('D:\Agent', 'D:\Agent\Work', 'D:\Agent\Work\_Temp')

$paths | % {
    $d = [System.IO.Directory]::CreateDirectory($_)
    $acl = Get-Acl $d.FullName
    $ar = new-object System.Security.AccessControl.FileSystemAccessRule("Everyone", "FullControl", "ContainerInherit, ObjectInherit", "None", "Allow")
    $acl.AddAccessRule($ar)
    Set-Acl $d.FullName -AclObject $acl
}
+1
SimonCropp on Jul 17, 2019
Read more comments on GitHub
← Runestone: Crash report
Bonito.jl: Page() fails in Pluto →