Can't update a row in table with IDENTITY as primary key

[NathZ1]

When trying to update an existing row of data, get a 500 Internal Server Error. Works fine for creating a new row.

Looking at the function logs -

Output binding -

Table structure -

CREATE TABLE [dbo].[config_rs](
	[ID] [int] IDENTITY(1,1) NOT NULL,
	[SQL_COLUMN] [varchar](50) NOT NULL,
	[DIVISION] [varchar](100) NOT NULL,
	[WARD] [varchar](6) NULL,
	[EXCLUDE_PARENT_DIV] [bit] NULL,
	[COMPARISON] [int] NULL,
	[OPERATOR] [varchar](20) NULL,
	[SCORE] [int] NOT NULL,
 CONSTRAINT [PK_config_rs] PRIMARY KEY CLUSTERED 
(
	[ID] ASC
)WITH (STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, OPTIMIZE_FOR_SEQUENTIAL_KEY = OFF) ON [PRIMARY]
) ON [PRIMARY]
GO

Request Payload -

[github-actions]

We need more info to debug your particular issue. If you could attach your logs to the issue, it would help us fix the issue much faster.

1. Set the default logging level to Debug and enable logging to a file. To do this ensure the following entries are in your host.json. (instructions)

{
  "logging": {
    "fileLoggingMode": "always",
    "logLevel": {
      "default": "Debug"
    }
  }
}

2. Restart your function and reproduce your issue

3. Get the log file and attach it to this issue. By default this will be in %TMP%/LogFiles/Application/Functions/Host.

NOTE Debug logging will include information such as Database and table names, if you do not wish to include this information you can either redact it from the logs before attaching or let us know and we will provide a way to send logs directly to us.

[lucyzhang929]

Hi @NathZ1, could you provide debug level logs? Thank you!

[Charles-Gagnon]

Can you verify that the row with the ID being updated actually exists in the table as well? That error should only show up if you're trying to insert a row for an ID that doesn't exist yet.

Note that the binding doesn't have any logic to handle checking whether the row already exists - so if you specify a value for the identity column and it doesn't exist then it will fail with that error.

[NathZ1]

Debug logs below - could this be a same / related error to one i reported a while ago - #624 (that i thought had since been fixed?) - I restarted the app, then created a new row (worked fine), then modified a row (failed). I then restarted the app again and edited a new row (worked fine), then created a new row (failed)...

Restart function app, then create new row:

2023-07-27T05:33:45Z   [Information]   Executing 'Functions.addRiskStrat' (Reason='This function was programmatically called via the host APIs.', Id=db08ef59-cff4-4dfa-a6f4-675c8bdbf4d2)
2023-07-27T05:33:45Z   [Verbose]   Sending invocation id: 'db08ef59-cff4-4dfa-a6f4-675c8bdbf4d2
2023-07-27T05:33:45Z   [Verbose]   Posting invocation id:db08ef59-cff4-4dfa-a6f4-675c8bdbf4d2 on workerId:ffe43c41-f126-4092-b561-391d713e4a3e
2023-07-27T05:33:46Z   [Information]   Sending event Create
2023-07-27T05:33:46Z   [Information]   Sending event AddAsync
2023-07-27T05:33:46Z   [Information]   Sending event FlushAsync
2023-07-27T05:33:46Z   [Verbose]   TID:12 BEGIN UpsertRowsAsync
2023-07-27T05:33:46Z   [Information]   Sending event TableInfoCacheMiss
2023-07-27T05:33:46Z   [Information]   Sending event GetTableInfoStart
2023-07-27T05:33:46Z   [Verbose]   TID:12 BEGIN RetrieveTableInformationAsync
2023-07-27T05:33:46Z   [Verbose]   TID:12 BEGIN GetCaseSensitivity Query="
                    SELECT
                        DATABASEPROPERTYEX('ppt-gch-test', 'Collation') AS Collation;"
2023-07-27T05:33:46Z   [Information]   Sending event GetCaseSensitivity
2023-07-27T05:33:46Z   [Verbose]   TID:29 END GetCaseSensitivity Duration=47ms
2023-07-27T05:33:46Z   [Verbose]   TID:29 BEGIN GetColumnDefinitions Query="
                    select
	                    COLUMN_NAME, DATA_TYPE +
		                    case
			                    when CHARACTER_MAXIMUM_LENGTH = -1 then '(max)'
			                    when CHARACTER_MAXIMUM_LENGTH <> -1 then '(' + cast(CHARACTER_MAXIMUM_LENGTH as varchar(4)) + ')'
                                when DATETIME_PRECISION is not null and DATA_TYPE not in ('datetime', 'date', 'smalldatetime') then '(' + cast(DATETIME_PRECISION as varchar(1)) + ')'
			                    when DATA_TYPE in ('decimal', 'numeric') then '(' + cast(NUMERIC_PRECISION as varchar(9)) + ',' + + cast(NUMERIC_SCALE as varchar(9)) + ')'
			                    else ''
		                    end as COLUMN_DEFINITION
                    from
	                    INFORMATION_SCHEMA.COLUMNS c
                    where
	                    c.TABLE_NAME = 'config_rs'
                    and
                        c.TABLE_SCHEMA = 'dbo'"
2023-07-27T05:33:46Z   [Information]   Sending event GetColumnDefinitions
2023-07-27T05:33:46Z   [Verbose]   TID:4 END GetColumnDefinitions Duration=19ms
2023-07-27T05:33:46Z   [Verbose]   TID:4 BEGIN GetPrimaryKeys Query="
                    SELECT
                        COLUMN_NAME, c.is_identity
                    FROM
                        INFORMATION_SCHEMA.TABLE_CONSTRAINTS tc
                    INNER JOIN
                        INFORMATION_SCHEMA.CONSTRAINT_COLUMN_USAGE ccu ON ccu.CONSTRAINT_NAME = tc.CONSTRAINT_NAME AND ccu.TABLE_NAME = tc.TABLE_NAME
                    INNER JOIN
                        sys.columns c ON c.object_id = OBJECT_ID('[dbo].[config_rs]') AND c.name = ccu.COLUMN_NAME
                    WHERE
                        tc.CONSTRAINT_TYPE = 'PRIMARY KEY'
                    and
                        tc.TABLE_NAME = 'config_rs'
                    and
                        tc.TABLE_SCHEMA = 'dbo'"
2023-07-27T05:33:46Z   [Information]   Sending event GetPrimaryKeys
2023-07-27T05:33:46Z   [Verbose]   TID:34 END GetPrimaryKeys Duration=4ms
2023-07-27T05:33:46Z   [Information]   Sending event GetTableInfoEnd
2023-07-27T05:33:46Z   [Verbose]   TID:34 END RetrieveTableInformationAsync Duration=81ms DB and Table: ppt-gch-test.dbo.config_rs. Primary keys: []. SQL Column and Definitions:  [[id, int],[sql_column, varchar(50)],[division, varchar(100)],[ward, varchar(6)],[exclude_parent_div, bit],[comparison, int],[operator, varchar(20)],[score, int]]
2023-07-27T05:33:46Z   [Information]   Sending event UpsertStart
2023-07-27T05:33:46Z   [Verbose]   TID:34 BEGIN UpsertRowsTransaction
2023-07-27T05:33:47Z   [Information]   Sending event UpsertEnd
2023-07-27T05:33:47Z   [Verbose]   TID:34 END UpsertRowsTransaction Duration=69ms Upserted 1 row(s) into database: ppt-gch-test and table: dbo.config_rs.
2023-07-27T05:33:47Z   [Verbose]   TID:34 END UpsertRowsAsync Duration=442ms
2023-07-27T05:33:47Z   [Information]   Executed 'Functions.addRiskStrat' (Succeeded, Id=db08ef59-cff4-4dfa-a6f4-675c8bdbf4d2, Duration=1774ms)

Then edit an existing row:

2023-07-27T05:35:15Z   [Information]   Executing 'Functions.addRiskStrat' (Reason='This function was programmatically called via the host APIs.', Id=6bb7a541-30aa-44d7-a201-6beaefb2eb5c)
2023-07-27T05:35:15Z   [Verbose]   Sending invocation id: '6bb7a541-30aa-44d7-a201-6beaefb2eb5c
2023-07-27T05:35:15Z   [Verbose]   Posting invocation id:6bb7a541-30aa-44d7-a201-6beaefb2eb5c on workerId:ffe43c41-f126-4092-b561-391d713e4a3e
2023-07-27T05:35:15Z   [Information]   Sending event Create
2023-07-27T05:35:15Z   [Information]   Sending event AddAsync
2023-07-27T05:35:15Z   [Information]   Sending event FlushAsync
2023-07-27T05:35:15Z   [Verbose]   TID:8 BEGIN UpsertRowsAsync
2023-07-27T05:35:15Z   [Information]   Sending event TableInfoCacheHit
2023-07-27T05:35:15Z   [Information]   Sending event UpsertStart
2023-07-27T05:35:15Z   [Verbose]   TID:8 BEGIN UpsertRowsTransaction
2023-07-27T05:35:15Z   [Information]   Sending exception event: An explicit value for the identity column in table 'dbo.config_rs' can only be specified when a column list is used and IDENTITY_INSERT is ON.
2023-07-27T05:35:15Z   [Information]   Sending exception event: An explicit value for the identity column in table 'dbo.config_rs' can only be specified when a column list is used and IDENTITY_INSERT is ON.
2023-07-27T05:35:15Z   [Error]   Executed 'Functions.addRiskStrat' (Failed, Id=6bb7a541-30aa-44d7-a201-6beaefb2eb5c, Duration=345ms)

Restart app, then edit an existing row:

2023-07-27T22:34:57Z   [Information]   Executing 'Functions.addRiskStrat' (Reason='This function was programmatically called via the host APIs.', Id=0f85b094-24db-42b7-aead-a90ae155a148)
2023-07-27T22:34:57Z   [Verbose]   Sending invocation id: '0f85b094-24db-42b7-aead-a90ae155a148
2023-07-27T22:34:57Z   [Verbose]   Posting invocation id:0f85b094-24db-42b7-aead-a90ae155a148 on workerId:945f2675-ac53-4072-ba12-4b3c517af2ab
2023-07-27T22:34:57Z   [Verbose]   Sending event Create
2023-07-27T22:34:57Z   [Verbose]   TID:8 BEGIN OpenSqlAsyncCollectorVerifyDatabaseSupportedConnection
2023-07-27T22:34:57Z   [Verbose]   TID:8 END OpenSqlAsyncCollectorVerifyDatabaseSupportedConnection
2023-07-27T22:34:57Z   [Verbose]   TID:8 BEGIN VerifyDatabaseSupported Query=SELECT compatibility_level FROM sys.databases WHERE Name = DB_NAME()
2023-07-27T22:34:57Z   [Verbose]   TID:33 END GetUserTableId CompatLevel=160
2023-07-27T22:34:57Z   [Verbose]   Sending event FlushAsync
2023-07-27T22:34:57Z   [Verbose]   TID:8 BEGIN UpsertRowsAsync
2023-07-27T22:34:57Z   [Verbose]   TID:8 BEGIN OpenUpsertRowsAsyncConnection
2023-07-27T22:34:57Z   [Verbose]   TID:8 END OpenUpsertRowsAsyncConnection
2023-07-27T22:34:57Z   [Verbose]   TID:8 BEGIN GetServerTelemetryProperties Query=SELECT SERVERPROPERTY('EngineEdition'), SERVERPROPERTY('Edition')
2023-07-27T22:34:57Z   [Verbose]   Sending event TableInfoCacheMiss
2023-07-27T22:34:57Z   [Verbose]   TID:12 BEGIN RetrieveTableInformationAsync
2023-07-27T22:34:57Z   [Verbose]   TID:12 BEGIN GetColumnDefinitions Query="
                    select
	                    COLUMN_NAME, DATA_TYPE +
		                    case
			                    when CHARACTER_MAXIMUM_LENGTH = -1 then '(max)'
			                    when CHARACTER_MAXIMUM_LENGTH <> -1 then '(' + cast(CHARACTER_MAXIMUM_LENGTH as varchar(4)) + ')'
                                when DATETIME_PRECISION is not null and DATA_TYPE not in ('datetime', 'date', 'smalldatetime') then '(' + cast(DATETIME_PRECISION as varchar(1)) + ')'
			                    when DATA_TYPE in ('decimal', 'numeric') then '(' + cast(NUMERIC_PRECISION as varchar(9)) + ',' + + cast(NUMERIC_SCALE as varchar(9)) + ')'
			                    else ''
		                    end as COLUMN_DEFINITION
                    from
	                    INFORMATION_SCHEMA.COLUMNS c
                    where
	                    c.TABLE_NAME = 'config_rs'
                    and
                        c.TABLE_SCHEMA = 'dbo'"
2023-07-27T22:34:57Z   [Verbose]   Sending event GetColumnDefinitions
2023-07-27T22:34:57Z   [Verbose]   TID:12 END GetColumnDefinitions Duration=13ms
2023-07-27T22:34:57Z   [Verbose]   TID:12 BEGIN GetPrimaryKeys Query="
                    SELECT
                        ccu.COLUMN_NAME,
                        c.is_identity,
                        case
                            when isc.COLUMN_DEFAULT = NULL then 'false'
                            else 'true'
                        end as has_default
                    FROM
                        INFORMATION_SCHEMA.TABLE_CONSTRAINTS tc
                    INNER JOIN
                        INFORMATION_SCHEMA.CONSTRAINT_COLUMN_USAGE ccu ON ccu.CONSTRAINT_NAME = tc.CONSTRAINT_NAME AND ccu.TABLE_NAME = tc.TABLE_NAME
                    INNER JOIN
                        sys.columns c ON c.object_id = OBJECT_ID('[dbo].[config_rs]') AND c.name = ccu.COLUMN_NAME
                    INNER JOIN
                        INFORMATION_SCHEMA.COLUMNS isc ON isc.TABLE_NAME = 'config_rs' AND isc.COLUMN_NAME = ccu.COLUMN_NAME
                    WHERE
                        tc.CONSTRAINT_TYPE = 'PRIMARY KEY'
                    and
                        tc.TABLE_NAME = 'config_rs'
                    and
                        tc.TABLE_SCHEMA = 'dbo'"
2023-07-27T22:34:59Z   [Verbose]   Sending event GetPrimaryKeys
2023-07-27T22:34:59Z   [Verbose]   TID:22 END GetPrimaryKeys Duration=2096ms
2023-07-27T22:34:59Z   [Verbose]   Sending event GetTableInfo
2023-07-27T22:34:59Z   [Verbose]   TID:22 END RetrieveTableInformationAsync Duration=2113ms DB and Table: ppt-gch-test.dbo.config_rs. Primary keys: [ID]. SQL Column and Definitions:  [[ID, int],[SQL_COLUMN, varchar(50)],[DIVISION, varchar(100)],[WARD, varchar(6)],[EXCLUDE_PARENT_DIV, bit],[COMPARISON, int],[OPERATOR, varchar(20)],[SCORE, int]] Object columns: [ID,SQL_COLUMN,DIVISION,WARD,EXCLUDE_PARENT_DIV,OPERATOR,COMPARISON,SCORE]
2023-07-27T22:34:59Z   [Verbose]   TID:22 BEGIN UpsertRowsTransaction
2023-07-27T22:34:59Z   [Verbose]   TID:22 UpsertRowsTransactionBatch - Query=WITH cte AS ( SELECT * FROM OPENJSON(@rowData) WITH ([ID] int,[SQL_COLUMN] varchar(50),[DIVISION] varchar(100),[WARD] varchar(6),[EXCLUDE_PARENT_DIV] bit,[OPERATOR] varchar(20),[COMPARISON] int,[SCORE] int) ) 
                    MERGE INTO [dbo].[config_rs] WITH (HOLDLOCK)
                        AS ExistingData
                    USING cte
                        AS NewData
                    ON
                        ExistingData.[ID] = NewData.[ID]
                    WHEN MATCHED THEN
                        UPDATE SET  ExistingData.[SQL_COLUMN] = NewData.[SQL_COLUMN], ExistingData.[DIVISION] = NewData.[DIVISION], ExistingData.[WARD] = NewData.[WARD], ExistingData.[EXCLUDE_PARENT_DIV] = NewData.[EXCLUDE_PARENT_DIV], ExistingData.[OPERATOR] = NewData.[OPERATOR], ExistingData.[COMPARISON] = NewData.[COMPARISON], ExistingData.[SCORE] = NewData.[SCORE]
                    WHEN NOT MATCHED THEN
                        INSERT ([SQL_COLUMN],[DIVISION],[WARD],[EXCLUDE_PARENT_DIV],[OPERATOR],[COMPARISON],[SCORE]) VALUES ([SQL_COLUMN],[DIVISION],[WARD],[EXCLUDE_PARENT_DIV],[OPERATOR],[COMPARISON],[SCORE]);
2023-07-27T22:34:59Z   [Verbose]   Sending event Upsert
2023-07-27T22:34:59Z   [Verbose]   TID:12 END UpsertRowsTransaction Duration=121ms Upserted 1 row(s) into database: ppt-gch-test and table: dbo.config_rs.
2023-07-27T22:34:59Z   [Verbose]   TID:12 END UpsertRowsAsync Duration=2358ms
2023-07-27T22:34:59Z   [Information]   Executed 'Functions.addRiskStrat' (Succeeded, Id=0f85b094-24db-42b7-aead-a90ae155a148, Duration=2671ms)

then create a new row:

2023-07-27T22:35:52Z   [Information]   Executing 'Functions.addRiskStrat' (Reason='This function was programmatically called via the host APIs.', Id=4f28f11e-f695-4e7a-aeb8-6be9ce5ae302)
2023-07-27T22:35:52Z   [Verbose]   Sending invocation id: '4f28f11e-f695-4e7a-aeb8-6be9ce5ae302
2023-07-27T22:35:52Z   [Verbose]   Posting invocation id:4f28f11e-f695-4e7a-aeb8-6be9ce5ae302 on workerId:945f2675-ac53-4072-ba12-4b3c517af2ab
2023-07-27T22:35:53Z   [Verbose]   Sending event Create
2023-07-27T22:35:53Z   [Verbose]   TID:8 BEGIN OpenSqlAsyncCollectorVerifyDatabaseSupportedConnection
2023-07-27T22:35:53Z   [Verbose]   TID:8 END OpenSqlAsyncCollectorVerifyDatabaseSupportedConnection
2023-07-27T22:35:53Z   [Verbose]   TID:8 BEGIN VerifyDatabaseSupported Query=SELECT compatibility_level FROM sys.databases WHERE Name = DB_NAME()
2023-07-27T22:35:53Z   [Verbose]   TID:43 END GetUserTableId CompatLevel=160
2023-07-27T22:35:53Z   [Verbose]   Sending event FlushAsync
2023-07-27T22:35:53Z   [Verbose]   TID:8 BEGIN UpsertRowsAsync
2023-07-27T22:35:53Z   [Verbose]   TID:8 BEGIN OpenUpsertRowsAsyncConnection
2023-07-27T22:35:53Z   [Verbose]   TID:8 END OpenUpsertRowsAsyncConnection
2023-07-27T22:35:53Z   [Verbose]   TID:8 BEGIN GetServerTelemetryProperties Query=SELECT SERVERPROPERTY('EngineEdition'), SERVERPROPERTY('Edition')
2023-07-27T22:35:53Z   [Verbose]   Sending event TableInfoCacheHit
2023-07-27T22:35:53Z   [Verbose]   TID:8 BEGIN UpsertRowsTransaction
2023-07-27T22:35:53Z   [Verbose]   TID:8 UpsertRowsTransactionBatch - Query=WITH cte AS ( SELECT * FROM OPENJSON(@rowData) WITH ([SQL_COLUMN] varchar(50),[DIVISION] varchar(100),[WARD] varchar(6),[EXCLUDE_PARENT_DIV] bit,[OPERATOR] varchar(20),[COMPARISON] int,[SCORE] int) ) 
                    MERGE INTO [dbo].[config_rs] WITH (HOLDLOCK)
                        AS ExistingData
                    USING cte
                        AS NewData
                    ON
                        ExistingData.[ID] = NewData.[ID]
                    WHEN MATCHED THEN
                        UPDATE SET  ExistingData.[SQL_COLUMN] = NewData.[SQL_COLUMN], ExistingData.[DIVISION] = NewData.[DIVISION], ExistingData.[WARD] = NewData.[WARD], ExistingData.[EXCLUDE_PARENT_DIV] = NewData.[EXCLUDE_PARENT_DIV], ExistingData.[OPERATOR] = NewData.[OPERATOR], ExistingData.[COMPARISON] = NewData.[COMPARISON], ExistingData.[SCORE] = NewData.[SCORE]
                    WHEN NOT MATCHED THEN
                        INSERT ([SQL_COLUMN],[DIVISION],[WARD],[EXCLUDE_PARENT_DIV],[OPERATOR],[COMPARISON],[SCORE]) VALUES ([SQL_COLUMN],[DIVISION],[WARD],[EXCLUDE_PARENT_DIV],[OPERATOR],[COMPARISON],[SCORE]);
2023-07-27T22:35:53Z   [Verbose]   Sending exception event: Invalid column name 'ID'.
2023-07-27T22:35:53Z   [Verbose]   Sending exception event: Unexpected error upserting rows
2023-07-27T22:35:53Z   [Error]   Executed 'Functions.addRiskStrat' (Failed, Id=4f28f11e-f695-4e7a-aeb8-6be9ce5ae302, Duration=312ms)

[Charles-Gagnon]

That does indeed look like the same issue...what version of the extension are you using? (or bundle in this case since it seems like a non-.NET language)

[Charles-Gagnon]

Ok, so think I found the issue (I'm able to repro it myself). The PR that you linked was specifically handling caching the query. So while that would be a problem here too, the issue you're running in to is that we are also caching the table info - and for this we use the row passed in to determine what columns to look up. In your situation the columns you pass in differ based on whether you're updating or inserting though and so the table info we cache won't always be correct.

In my testing I found that if you set the cache timeout to 0 though it will recalculate the table info every query, and thus not run into this issue. You can do this by using the AZ_FUNC_TABLE_INFO_CACHE_TIMEOUT_MINUTES var and set that to 0. This isn't an officially document/supported var but as long as you're ok with the extra overhead from this then it should unblock you while we figure out a better solution.

Found a better solution, if you make sure to ALWAYS include the ProductId column in your payload - but just give it a null value when inserting a new item - then that should also fix the issue. Let me know if that doesn't work.

e.g.

{
    "ProductId": null,
    "Name": "Test",
    "Cost": 100
}

[Charles-Gagnon]

Some notes for us to consider:

• Why are we only retrieving the columns in the object for the table info? Wouldn't it be better to fetch the table in its entirety and save us having to ever worry about whether the columns passed in are different?
• Identity columns are a special case, so let's make sure we're fully considering how they're handled. They're the only values that may or may not exist. Maybe we should treat them as "required" in the definition but null for inserts?

[NathZ1]

Found a better solution, if you make sure to ALWAYS include the ProductId column in your payload - but just give it a null value when inserting a new item - then that should also fix the issue. Let me know if that doesn't work.

Can confirm that this works.