Here is a full stack trace on that error.

Server Error in '/' Application.

A catalog content reference of type Catalog is invalid in this operation, only entries and nodes have codes.
Parameter name: contentLink

Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code. 

Exception Details: System.ArgumentException: A catalog content reference of type Catalog is invalid in this operation, only entries and nodes have codes.
Parameter name: contentLink

Source Error: 

Stack Trace: 

[ArgumentException: A catalog content reference of type Catalog is invalid in this operation, only entries and nodes have codes.
Parameter name: contentLink]
   Mediachase.Commerce.Catalog.ReferenceConverter.GetCode(ContentReference contentLink) +430
   EPiServer.Commerce.Shell.Rest.RelationStore.CreateModel(Relation relation, RelationRequestMode relationRequestMode) +516
   System.Linq.WhereSelectEnumerableIterator`2.MoveNext() +223
   System.Collections.Generic.List`1..ctor(IEnumerable`1 collection) +436
   System.Linq.Enumerable.ToList(IEnumerable`1 source) +70
   EPiServer.Shell.Services.Rest.ItemRange.ApplyTo(IEnumerable`1 items) +216
   EPiServer.Shell.Services.Rest.RestControllerBase.Rest(IEnumerable`1 data, ItemRange range) +21
   lambda_method(Closure , ControllerBase , Object[] ) +334
   System.Web.Mvc.ReflectedActionDescriptor.Execute(ControllerContext controllerContext, IDictionary`2 parameters) +229
   System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary`2 parameters) +35
   System.Web.Mvc.Async.AsyncControllerActionInvoker.<BeginInvokeSynchronousActionMethod>b__39(IAsyncResult asyncResult, ActionInvocation innerInvokeState) +39
   System.Web.Mvc.Async.WrappedAsyncResult`2.CallEndDelegate(IAsyncResult asyncResult) +67
   System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethod(IAsyncResult asyncResult) +42
   System.Web.Mvc.Async.AsyncInvocationWithFilters.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3d() +72
   System.Web.Mvc.Async.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f() +385
   System.Web.Mvc.Async.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f() +385
   System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethodWithFilters(IAsyncResult asyncResult) +42
   System.Web.Mvc.Async.<>c__DisplayClass2b.<BeginInvokeAction>b__1c() +38
   System.Web.Mvc.Async.<>c__DisplayClass21.<BeginInvokeAction>b__1e(IAsyncResult asyncResult) +185
   System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeAction(IAsyncResult asyncResult) +38
   EPiServer.Shell.Services.Rest.RestControllerBase.EndExecute(IAsyncResult asyncResult) +60
   System.Web.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() +607
   System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously) +134

Version Information: Microsoft .NET Framework Version:4.0.30319; ASP.NET Version:4.7.2053.0

And the url that's being called on the back end is.. 
/EPiServer/EPiServer.Commerce.Shell/Stores/relation/?referenceId=1073742426_469854_CatalogContent&relationTypes=1&dojo.preventCache=1504881943177

Hi,

We are aware of this problem (the exception), it was filed as bug COM-5404 and will be fixed in upcoming releases.

Sorry for this inconvenience.

/Q

I, in other hands, tested publishing content and it's fine (there is no noticable slowness). Can you do a profiling to see why it's slow? Perhaps because you have some event listeners somewhere?

I'm working on the profiler now. One thing I have seen is the hangup appears to occur while sending a Requestion Payload of..

{action: 3}

To the url... /EPiServer/cms/Stores/contentdata/1079_466551_CatalogContent

I'm guessing that action = 3 is publish, and this is the HTTP call out to your api to publish this content, correct?

-Paul

Using SQL Express profiler I pinpointed the issue. For some reason when I run [ecfVersion_ListFiltered], it crawls. It takes about 36 seconds. I confirmed in SQL profiler that this is executed every publish. I saw there was a bug (COM-4792) reported for this stored procedure, but I'm still seeing very poor performance with this even though this bug was marked as being closed in 11.1.0, and I'm on 11.1.1.

What is this stored procedure anyway?

I have like 1.5 million rows in the ecfversion table and I think it doesn't like this. Every instance of where this stored proc was hit, it returned 0 records and took forever. To test, I commented out the innards of the stored procedure, and replaced it with an empty query that returned the same columns. My publish is flying now.

Obviously this isn't a long term solution. What should my next steps be? Contact Episerver support services?

-Paul

<p>That is very strange. I suspect you might be experiencing "parameter sniff" problem. If you run the query which takes 36 seconds, how does the execution plan look like? Can you export it and post it here?</p>

I had a simular issue before with a different stored proc, but that issue was resolved when I cleared statistics. I tried clearing it again to see if it would fix this issue, and it did nothing.

-Paul

If you have few minutes to spare (to grab the execution plans and post them here) - I'd be happy to look into them :) 

I just got an execution plan. You can find it here.

https://drive.google.com/file/d/0B8wuTg7wzPjYbGVtTVlRZ1lpLTA/view?usp=sharing

I uploaded it to my google drive, which makes it show up as an audio file but if you download it, it should open correctly.

Once again, thanks for you help with this Quan.

-Paul

Just a heads up, I did just submit a support request for this issue.

I'm looking into the execution plan. However this is running with status = 6, so this is to load the delayed publish versions (i.e. it's used to run the Publish deplayed publish versions scheduled job).

I'm not sure why this is related to your publishing ...

Not sure what you mean by a status = 6. The stored procedure I'm running to test/the one I've seen in sql profiler while publishing is..

declare @p3 dbo.udttIdTable 
insert into @p3 values(6)

exec ecfVersion_ListFiltered @StartIndex=0,@MaxRows=2147483646,@Statuses=@p3 
go

ah, I just realized what you're saying. You're refering too... insert into @p3 values(6).

I'm not sure exactly why this is being called, but it is. Consistantly. And we've edited nothing that should change this.

One way to resolve the problem, is to run the scheduled job I mentioned - Publish Delayed Content Versions - which will publish the delayed publish versions and make that specific query very fast (as there is no "Delayed publish version" in ecfVersion)

I'll look into why it's called. I would say it has no reason to run - but there might be something I don't know. 

Would you be able to point me to a good resource on how to run this job? 

I do see something that sounds like what you're saying in the CMS admin, but it says it's running with no issues.

Now it's the interesting part, I modified the SP to be like this

ALTER PROCEDURE [dbo].[ecfVersion_ListFiltered]
(
    @ObjectId INT = NULL,
    @ObjectTypeId INT = NULL,
    @ModifiedBy NVARCHAR(255) = NULL,
    @Languages [udttLanguageCode] READONLY,
    @Statuses [udttIdTable] READONLY,
    @StartIndex INT,
    @MaxRows INT
)
AS

BEGIN    
    SET NOCOUNT ON

    DECLARE @StatusCount INT
    SELECT @StatusCount = COUNT(*) FROM @Statuses

    DECLARE @LanguageCount INT
    SELECT @LanguageCount = COUNT(*) FROM @Languages

	DECLARE @status INT 
	SET @status = (SELECT TOP 1 Id FROM @Statuses)
	IF (@StatusCount = 1 AND @status = 6)
	BEGIN
	 RAISERROR (15600,-1,-1, 'Whyyyy');  

	END

    
    IF @StartIndex = 0 AND @MaxRows = 2147483646
    BEGIN
        SELECT WorkId, ObjectId, ObjectTypeId, Name, LanguageName, MasterLanguageName, IsCommonDraft, StartPublish, ModifiedBy, Modified, [Status]
        FROM
            dbo.ecfVersion vn
        WHERE
            [dbo].ecf_IsCurrentLanguageRemoved(vn.CatalogId, vn.LanguageName) = 0 AND
            ((@ObjectId IS NULL) OR vn.ObjectId = @ObjectId) AND
            ((@ObjectTypeId IS NULL) OR vn.ObjectTypeId = @ObjectTypeId) AND
            ((@ModifiedBy IS NULL) OR vn.ModifiedBy = @ModifiedBy) AND
            ((@StatusCount = 0) OR (vn.[Status] IN (SELECT ID FROM @Statuses))) AND
            ((@LanguageCount = 0) OR (vn.LanguageName IN (SELECT LanguageCode FROM @Languages)))
    END
    ELSE
    BEGIN
    ;WITH TempResult as
    (
        SELECT ROW_NUMBER() OVER(ORDER BY vn.Modified DESC) as RowNumber, vn.*
        FROM
            dbo.ecfVersion vn
        WHERE
            [dbo].ecf_IsCurrentLanguageRemoved(vn.CatalogId, vn.LanguageName) = 0 AND
            ((@ObjectId IS NULL) OR vn.ObjectId = @ObjectId) AND
            ((@ObjectTypeId IS NULL) OR vn.ObjectTypeId = @ObjectTypeId) AND
            ((@ModifiedBy IS NULL) OR vn.ModifiedBy = @ModifiedBy) AND
            ((@StatusCount = 0) OR (vn.[Status] IN (SELECT ID FROM @Statuses))) AND
            ((@LanguageCount = 0) OR (vn.LanguageName IN (SELECT LanguageCode FROM @Languages)))
    )
    
    SELECT  WorkId, ObjectId, ObjectTypeId, Name, LanguageName, MasterLanguageName, IsCommonDraft, StartPublish, ModifiedBy, Modified, [Status], (SELECT COUNT(*) FROM TempResult) AS TotalRows
    FROM    TempResult
    WHERE    RowNumber BETWEEN (@StartIndex + 1) AND (@MaxRows + @StartIndex)
    END
           
END

So if it's called with the parameter as you tried, it would raise an error. 

• Tried with the scheduled job, it throws error, so it works as expected.
• Tried publishing a product. everything went smooth as butter :)

Can you try the same on your machine?

That's didn't help performance, but I modified it slightly and now it's great.

The problem was that RAISEERROR doesn't actually stop the stored procedure from continuing to execute, it just raises an error. I added a RETURN below that and it's lightning now.

Here's my full query...

RAISERROR 

USE [EPiServer.CommerceManager]
GO

/****** Object:  StoredProcedure [dbo].[ecfVersion_ListFiltered]    Script Date: 9/11/2017 11:11:26 AM ******/
SET ANSI_NULLS ON
GO

SET QUOTED_IDENTIFIER ON
GO

ALTER PROCEDURE [dbo].[ecfVersion_ListFiltered]
(
    @ObjectId INT = NULL,
    @ObjectTypeId INT = NULL,
    @ModifiedBy NVARCHAR(255) = NULL,
    @Languages [udttLanguageCode] READONLY,
    @Statuses [udttIdTable] READONLY,
    @StartIndex INT,
    @MaxRows INT
)
AS

BEGIN    
    SET NOCOUNT ON

    DECLARE @StatusCount INT
    SELECT @StatusCount = COUNT(*) FROM @Statuses

    DECLARE @LanguageCount INT
    SELECT @LanguageCount = COUNT(*) FROM @Languages

	DECLARE @status INT 
	SET @status = (SELECT TOP 1 Id FROM @Statuses)
	IF (@StatusCount = 1 AND @status = 6)
	BEGIN
	 RAISERROR (15600,-1,-1, 'Whyyyy');  
	 RETURN;

	END

    
    IF @StartIndex = 0 AND @MaxRows = 2147483646
    BEGIN
        SELECT WorkId, ObjectId, ObjectTypeId, Name, LanguageName, MasterLanguageName, IsCommonDraft, StartPublish, ModifiedBy, Modified, [Status]
        FROM
            dbo.ecfVersion vn
        WHERE
            [dbo].ecf_IsCurrentLanguageRemoved(vn.CatalogId, vn.LanguageName) = 0 AND
            ((@ObjectId IS NULL) OR vn.ObjectId = @ObjectId) AND
            ((@ObjectTypeId IS NULL) OR vn.ObjectTypeId = @ObjectTypeId) AND
            ((@ModifiedBy IS NULL) OR vn.ModifiedBy = @ModifiedBy) AND
            ((@StatusCount = 0) OR (vn.[Status] IN (SELECT ID FROM @Statuses))) AND
            ((@LanguageCount = 0) OR (vn.LanguageName IN (SELECT LanguageCode FROM @Languages)))
    END
    ELSE
    BEGIN
    ;WITH TempResult as
    (
        SELECT ROW_NUMBER() OVER(ORDER BY vn.Modified DESC) as RowNumber, vn.*
        FROM
            dbo.ecfVersion vn
        WHERE
            [dbo].ecf_IsCurrentLanguageRemoved(vn.CatalogId, vn.LanguageName) = 0 AND
            ((@ObjectId IS NULL) OR vn.ObjectId = @ObjectId) AND
            ((@ObjectTypeId IS NULL) OR vn.ObjectTypeId = @ObjectTypeId) AND
            ((@ModifiedBy IS NULL) OR vn.ModifiedBy = @ModifiedBy) AND
            ((@StatusCount = 0) OR (vn.[Status] IN (SELECT ID FROM @Statuses))) AND
            ((@LanguageCount = 0) OR (vn.LanguageName IN (SELECT LanguageCode FROM @Languages)))
    )
    
    SELECT  WorkId, ObjectId, ObjectTypeId, Name, LanguageName, MasterLanguageName, IsCommonDraft, StartPublish, ModifiedBy, Modified, [Status], (SELECT COUNT(*) FROM TempResult) AS TotalRows
    FROM    TempResult
    WHERE    RowNumber BETWEEN (@StartIndex + 1) AND (@MaxRows + @StartIndex)
    END
           
END
GO

So typically I don't like adding modified stored procedures to my production envionrmnet until it's officially sanctioned? You wrote this, so I do feel better about it than if I'd written it. Is there any way we could get this added to a future epi release?

-Paul

No, the point is not to making it fast. The point is to find out which code called that SP. With that raiseerror you should be able to see the exception, and from stacktrace we can trace which code called that SP.

When we know that we might find a way to fix it, but that change was not intended to fix the performance issue. 

Here's my logged error.

Error Number:15600,State:1,Class:15
2017-09-11 11:54:53,983 [7] ERROR EPiServer.Cms.Shell.Workspace.Committers.Internal.ContentDataCommitter: Unexpected error when saving 1073742426_469883_CatalogContent
System.Data.SqlClient.SqlException (0x80131904): An invalid parameter or option was specified for procedure 'Whyyyy'.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
at System.Data.SqlClient.SqlDataReader.get_MetaData()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
at EPiServer.Data.Providers.SqlTransientErrorsRetryPolicy.Execute[TResult](Func`1 method)
at Mediachase.Data.Provider.SqlDataProvider.LoadReader(DataCommand command)
at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteReader(String connectionString, CommandType commandType, String commandText, DataParameter[] commandParameters)
at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.ExecuteSproc[T](Func`5 dbExecutor, String sproc, IEnumerable`1 parameters)
at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.List(VersionFilter filter, Int32 startIndex, Int32 maxRows)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass26_0.<List>b__9()
at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.List(VersionFilter filter, Int32 startIndex, Int32 maxRows, Int32& totalCount)
at EPiServer.Core.IContentVersionRepositoryExtensions.ListDelayedPublish(IContentVersionRepository contentVersionRepository)
at EPiServer.Commerce.Catalog.Provider.CatalogContentProvider.ListDelayedPublish()
at EPiServer.Core.Internal.DefaultContentRepository.<>c__DisplayClass45_0.<ListDelayedPublish>b__0(ContentProvider contentProvider)
at EPiServer.Core.ContentProviderMap.Iterate(Action`1 contentProviderHandler)
at EPiServer.Core.Internal.DefaultContentRepository.ListDelayedPublish()
at EPiServer.ContentCollaboration.CMSContentCollaborationBroadcaster.contentEvents_PublishingContent(Object sender, ContentEventArgs e)
at System.EventHandler`1.Invoke(Object sender, TEventArgs e)
at EPiServer.Core.Internal.DefaultContentEvents.RaiseCancellableContentEvent(String key, String defaultReason, ContentEventArgs eventArgs)
at EPiServer.Core.Internal.DefaultContentRepository.RaisePreSaveEvents(SaveContentEventArgs eventArgs, StatusTransition transition, Boolean isNew, Boolean isNewLanguageBranch)
at EPiServer.Core.Internal.DefaultContentRepository.Save(IContent content, SaveAction action, AccessLevel access)
at EPiServer.Cms.Shell.Service.Internal.ContentService.Save(IContent content, SaveAction saveAction, AccessLevel accessLevel)
at EPiServer.Cms.Shell.Workspace.Committers.Internal.ContentDataCommitter.Commit(EditContentData change, CommitArguments argument)
ClientConnectionId:e2faf39f-64e4-4e1a-92de-d83ab3f4d590
Error Number:15600,State:1,Class:15
System.Data.SqlClient.SqlException (0x80131904): An invalid parameter or option was specified for procedure 'Whyyyy'.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
at System.Data.SqlClient.SqlDataReader.get_MetaData()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
at EPiServer.Data.Providers.SqlTransientErrorsRetryPolicy.Execute[TResult](Func`1 method)
at Mediachase.Data.Provider.SqlDataProvider.LoadReader(DataCommand command)
at Mediachase.MetaDataPlus.Common.DBHelper.ExecuteReader(String connectionString, CommandType commandType, String commandText, DataParameter[] commandParameters)
at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.ExecuteSproc[T](Func`5 dbExecutor, String sproc, IEnumerable`1 parameters)
at EPiServer.Commerce.Catalog.DataAccess.CatalogContentVersionDB.List(VersionFilter filter, Int32 startIndex, Int32 maxRows)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.<>c__DisplayClass26_0.<List>b__9()
at EPiServer.Framework.Cache.ObjectInstanceCacheExtensions.ReadThroughWithWait[T](IObjectInstanceCache cache, String cacheKey, Func`1 readValue, Func`2 evictionPolicy)
at EPiServer.Commerce.Catalog.Provider.CatalogContentVersionStore.List(VersionFilter filter, Int32 startIndex, Int32 maxRows, Int32& totalCount)
at EPiServer.Core.IContentVersionRepositoryExtensions.ListDelayedPublish(IContentVersionRepository contentVersionRepository)
at EPiServer.Commerce.Catalog.Provider.CatalogContentProvider.ListDelayedPublish()
at EPiServer.Core.Internal.DefaultContentRepository.<>c__DisplayClass45_0.<ListDelayedPublish>b__0(ContentProvider contentProvider)
at EPiServer.Core.ContentProviderMap.Iterate(Action`1 contentProviderHandler)
at EPiServer.Core.Internal.DefaultContentRepository.ListDelayedPublish()
at EPiServer.ContentCollaboration.CMSContentCollaborationBroadcaster.contentEvents_PublishingContent(Object sender, ContentEventArgs e)
at System.EventHandler`1.Invoke(Object sender, TEventArgs e)
at EPiServer.Core.Internal.DefaultContentEvents.RaiseCancellableContentEvent(String key, String defaultReason, ContentEventArgs eventArgs)
at EPiServer.Core.Internal.DefaultContentRepository.RaisePreSaveEvents(SaveContentEventArgs eventArgs, StatusTransition transition, Boolean isNew, Boolean isNewLanguageBranch)
at EPiServer.Core.Internal.DefaultContentRepository.Save(IContent content, SaveAction action, AccessLevel access)
at EPiServer.Cms.Shell.Service.Internal.ContentService.Save(IContent content, SaveAction saveAction, AccessLevel accessLevel)
at EPiServer.Cms.Shell.Workspace.Committers.Internal.ContentDataCommitter.Commit(EditContentData change, CommitArguments argument)
ClientConnectionId:e2faf39f-64e4-4e1a-92de-d83ab3f4d590

Apparently this relates to the Content Collaboration add-on. It listens to the events raised when saving content and decides tocall ListDelayedPublish. I guess every time if you consistently see this slowness. 

Are you actively using this add-on or is it something that you could uninstall to be able to move on (then we should of course continue to figure out why the add-on has this behavior)?

I still wonder why the scheduled job was very fast before and then suddenly it took 15 seconds. It's worth noting that it is very hard, if not impossible to optimize the SP when it comes to statuses, because there are only maximum 8 values of them, (normally, only 4 or 5), so adding an index here is not gonna help.

Unverified speculation: Maybe the scheduled job uses paging when pulling the result and the Content Collaboration code does not? When paging is specified, it uses another branch of the sproc.

That should not be the case - we only have one ecfVersion_ListFiltered, and the paging is actually heavier than without the paging 

When this job runs, it takes about 16 to 18 seconds. Because you put that increase into question, I looked into this and that low was artificially deflated because during my testing I commented out the inside of that stored procedure and had it return an empty result set that matched the stored procedures return result.

Then when it went back up was when I restored the original stored proc. You can see now, it's pretty consistant.

Removing the content collaboration module fixed this issue for me. Looking at it, it looks like this module hasn't been updated for the most recent version anyway. We removed it and it's working fast now.

Could you guys report this as a ContentCollaboration bug? I looked and it doesn't appear I have the ability to submit bugs.