microsoft / navcontainerhelper

Official Microsoft repository for BcContainerHelper, a PowerShell module, which makes it easier to work with Business Central Containers on Docker.
MIT License
385 stars 246 forks source link

ForceHandleTrackingEvent #504

Closed BertDeTemmerman closed 5 years ago

BertDeTemmerman commented 5 years ago

Describe the bug Just got the same problem as #5062 when trying to install my extension on a freshly made docker container. Version: Platform 14.0.32600.0 + Application 32615 (BE Dynamics NAV 14.1) tag: mcr.microsoft.com/businesscentral/sandbox:be

Manually installing the extension gives 'something went wrong' screen

using PS

PS C:\Windows\system32> Install-NavContainerApp -appName Drr -containerName Drr
Installing Drr on default
ForceHandleTrackingEvent failed to acquire a lock
at <ScriptBlock>, <No file>: line 12
ForceHandleTrackingEvent failed to acquire a lock
At C:\Program Files\WindowsPowerShell\Modules\navcontainerhelper\0.6.1.2\ContainerHandling\Invoke-ScriptInNavContainer.ps1:30 char:13
+             Invoke-Command -Session $session -ScriptBlock $scriptbloc ...
+             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : InvalidOperation: (:) [Install-NAVApp], InvalidOperationException
    + FullyQualifiedErrorId : MicrosoftDynamicsNavServer$NAV/default,Microsoft.Dynamics.Nav.Apps.Management.Cmdlets.InstallNavApp
    + PSComputerName        : f035387ac20db8dea0b56ae75fdc7e1e752215fe9980601d0774f10853724807

Publish (F5) from VS Code gives the same error. App compiles.

BertDeTemmerman commented 5 years ago

Logged out and back on on server

PS C:\Windows\system32> WARNING: The names of some imported commands from the module 'navcontainerhelper' include unapproved verbs that might make them less discoverable. To find the com
mands with unapproved verbs, run the Import-Module command again with the Verbose parameter. For a list of approved verbs, type Get-Verb.
Install-NavContainerApp -appName Drr -containerName Drr
Installing Drr on default
The extension 'Drr by E 0.0.0.2' is not synchronized.
at <ScriptBlock>, <No file>: line 12
The extension 'Drr by E 0.0.0.2' is not synchronized.
At C:\Program Files\WindowsPowerShell\Modules\navcontainerhelper\0.6.1.2\ContainerHandling\Invoke-ScriptInNavContainer.ps1:30 char:13
+             Invoke-Command -Session $session -ScriptBlock $scriptbloc ...
+             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : InvalidOperation: (:) [Install-NAVApp], InvalidOperationException
    + FullyQualifiedErrorId : MicrosoftDynamicsNavServer$NAV/default,Microsoft.Dynamics.Nav.Apps.Management.Cmdlets.InstallNavApp
    + PSComputerName        : f035387ac20db8dea0b56ae75fdc7e1e752215fe9980601d0774f10853724807

PS C:\Windows\system32> Sync-NavContainerApp -appName Drr -containerName Drr
Synchronizing  on default
App successfully synchronized

PS C:\Windows\system32> Install-NavContainerApp -appName Drr -containerName Drr
Installing Drr on default
App successfully installed

App is installed So relogging fixed it

BertDeTemmerman commented 5 years ago

Having it again, when republishing ... can't relog each time i need to publish ... :(

atoader commented 5 years ago

@SirBETE can you set the MetadataLockTimeout server setting to a value greater than "0:10:0"?

BertDeTemmerman commented 5 years ago

How can I set that? Get-NavContainerServerConfiguration -ContainerName X Doesn't give me that property

BertDeTemmerman commented 5 years ago

got the issue again, even after logging off and back on

but with Get-NavContainerDebugInfo -containerName X I got:

TimeGenerated : 6/25/2019 2:51:45 PM",
                           "EntryType     : Error",
                           "Message       : Server instance: NAV",
                           "                Category: Extensions",
                           "                ClientSessionId: 97f80642-216c-4a9f-b0eb-3f174ef23398",
                           "                ClientActivityId: 6a1aeca9-6836-49c6-a088-3e5a534ddea8",
                           "                ServerSessionUniqueId: 3a13e537-2217-498b-9907-0e22271a6689",
                           "                ServerActivityId: 0d0f4df2-afb8-4387-953c-1cb8f808a70d",
                           "                EventTime: 06/25/2019 12:51:45",
                           "                Message App Sync Exception -- Microsoft.Dynamics.Nav.Types.Exce",
                           "                ptions.NavLockTimeoutException: ForceHandleTrackingEvent ",
                           "                failed to acquire a lock",
                           "                   at Microsoft.Dynamics.Nav.Runtime.NavDatabaseChangeListener.",
                           "                ForceHandleTrackingEvent()",
                           "                   at Microsoft.Dynamics.Nav.Runtime.NavSqlMetadata.LockAppData",
                           "                baseForChangesToMetadata(NavSqlConnectionScope conScope)",
                           "                   at Microsoft.Dynamics.Nav.Runtime.NavSqlDatabaseSync.HandleA",
                           "                cquireAppDatabaseLockWithRetries(NavSqlConnectionScope ",
                           "                appDatabaseScope)",
                           "                   at Microsoft.Dynamics.Nav.Runtime.NavSqlDatabaseSync.Synchro",
                           "                nizeTenantDatabaseForAppSyncInternal(NavSession session)",
                           "                ProcessId: 11924",
                           "                Tag: 00001X1",
                           "                ThreadId: 40",
                           "                CounterInformation: ",
                           "",

during syncing of app

Installing app via webclient or powershell fails Via windows client,, it works :D

Get-NavContainerEventLog -containerName X Gives:

The description for Event ID 0 from source Microsoft.Dynamics.Nav.Management.dll cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.

If the event originated on another computer, the display information had to be saved with the event.

The following information was included with the event:

Type: System.InvalidOperationException Message: ForceHandleTrackingEvent failed to acquire a lock HResult: -2146233079

The description for Event ID 701 from source MicrosoftDynamicsNavServer$NAV cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.

If the event originated on another computer, the display information had to be saved with the event.

The following information was included with the event:

Server instance: NAV Category: Extensions ClientSessionId: 97f80642-216c-4a9f-b0eb-3f174ef23398 ClientActivityId: 6a1aeca9-6836-49c6-a088-3e5a534ddea8 ServerSessionUniqueId: 3a13e537-2217-498b-9907-0e22271a6689 ServerActivityId: 0d0f4df2-afb8-4387-953c-1cb8f808a70d EventTime: 06/25/2019 12:51:45 Message App Sync Exception -- Microsoft.Dynamics.Nav.Types.Exceptions.NavLockTimeoutException: ForceHandleTrackingEvent failed to acquire a lock at Microsoft.Dynamics.Nav.Runtime.NavDatabaseChangeListener.ForceHandleTrackingEvent() at Microsoft.Dynamics.Nav.Runtime.NavSqlMetadata.LockAppDatabaseForChangesToMetadata(NavSqlConnectionScope conScope) at Microsoft.Dynamics.Nav.Runtime.NavSqlDatabaseSync.HandleAcquireAppDatabaseLockWithRetries(NavSqlConnectionScope appDatabaseScope) at Microsoft.Dynamics.Nav.Runtime.NavSqlDatabaseSync.SynchronizeTenantDatabaseForAppSyncInternal(NavSession session) ProcessId: 11924 Tag: 00001X1 ThreadId: 40 CounterInformation:

The description for Event ID 705 from source MicrosoftDynamicsNavServer$NAV cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.

If the event originated on another computer, the display information had to be saved with the event.

The following information was included with the event:

Server instance: NAV Category: Runtime ClientSessionId: 97f80642-216c-4a9f-b0eb-3f174ef23398 ClientActivityId: 6a1aeca9-6836-49c6-a088-3e5a534ddea8 ServerSessionUniqueId: e2cc16c4-dc21-48ee-8d69-92773e379d10 ServerActivityId: db0f1b72-7736-4194-9c9b-9d4b9b28d02e EventTime: 06/25/2019 12:51:45 Message ForceHandleTrackingEvent failed to acquire a lock ProcessId: 11924 Tag: 000093D ThreadId: 40 CounterInformation:

Entered NAVcontainer and searched for that dll [X]: PS C:\Run> Get-ChildItem -Include Microsoft.Dynamics.Nav.Management.dll -File -Recurse -Path C:\

Directory: C:\navpfiles\140\RoleTailored Client

Mode LastWriteTime Length Name


-a---- 22/05/2019 12:51 386688 Microsoft.Dynamics.Nav.Management.dll

Directory: C:\Program Files\Microsoft Dynamics NAV\140\Service

Mode LastWriteTime Length Name


-a---- 22/05/2019 12:51 386688 Microsoft.Dynamics.Nav.Management.dll
-a---- 22/05/2019 12:51 1724752 Microsoft.Dynamics.Nav.Management.dll-Help.xml

Directory: C:\Program Files (x86)\Microsoft Dynamics NAV\140\RoleTailored Client

Mode LastWriteTime Length Name


-a---- 22/05/2019 12:51 386688 Microsoft.Dynamics.Nav.Management.dll

atoader commented 5 years ago

@freddydk can you help?

freddydk commented 5 years ago

https://github.com/microsoft/navcontainerhelper/issues/488 describes how to set that setting during creation of the container

kine commented 5 years ago

Hi @freddydk, when the fix will be released? To know if I should implement the workaround or it will be solved by new version of module. Thanks!

freddydk commented 5 years ago

I assume that this is fixed in CU2 - I wasn't planning on making a fix in the containerhelper for that specific version

BertDeTemmerman commented 5 years ago

Great, that other thread didn't showed up in google searches ... :( Anyway:

CU2 is due for?

Tried it with -additionalParameters @("--env CustomNavSettings=MetadataLockTimeout=""00:11:00""") (more than 10 min) made new container of versions Version: 14.1.33107.0-BE Platform: 14.0.32600.33003 Generic Tag: 0.0.9.8 Container OS Version: 10.0.14393.3025 (ltsc2016) Host OS Version: 10.0.14393.3053 (ltsc2016)

Let it run for half an hour: [2019-06-26 09:18:44.68] Sending request to http://x:7049/NAV/dev/apps?SchemaUpdateMode=synchronize [2019-06-26 09:55:43.66] The request for path /NAV/dev/apps?SchemaUpdateMode=synchronize failed with code 422. Reason: The following SQL error was unexpected: Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

E: tried to reinstall the extension again in Windows client, now it succeeded! Very strange ...