Conflict detected incorrectly.

[Jason van Beukering]

• In some circumstances IC detects a potential conflict when pushing code changes to an org even when I’ve recently retrieved the latest code (see attached screenshot).
• I refreshed the code approximately a day after the code change had been made (i.e. code change on the 11th, pulled latest code on the 12)

‌

[Scott Wells]

Hi, Jason. Please enable debug logging for Metadata Deployment, reproduce the behavior, and either attach or email the resulting idea.log for review. It should show the timestamp comparisons used by IC2 to determine whether something is in conflict. An even more useful log would include debug logging for Metadata Retrieval and retrieval of the metadata object being reported as a conflict before the subsequent deployment.

[Jason van Beukering]

Just got a conflict notification after having retrieved the latest code.... Please find attached log

[Scott Wells]

Thanks, Jason. Unfortunately I’m not seeing the retrieval aspect in the provided log. Please make sure that debug logging is also enabled for Metadata Retrieval, reproduce the issue, and include the contents of the various idea*.log* files from the span of the retrieval until the false conflict report. You can specifically look for a log entry like:

Updating timestamp for <path> to <date>.

from the metadata retrieval, and later you’ll see entries like:

2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Comparing local to server timestamps for classes/ML_DAL_TestDataFactory.cls:
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   lastDeployedOrRetrievedDate = Wed Aug 16 16:55:18 SAST 2023
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   serverLastModifiedDate      = Wed Aug 16 16:55:18 SAST 2023
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   localLastModifiedDate       = Thu Aug 17 06:47:11 SAST 2023 (raw)
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   localLastModifiedDate       = Thu Aug 17 06:47:12 SAST 2023 (adjusted)
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Local file newer than server representation: classes/ML_DAL_TestDataFactory.cls
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Server file was last modified by a different user (expected 0054J000000uyI4QAI, found 0052500000AhcR4AAJ): classes/ML_DAL_TestDataFactory.cls
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Comparing local to server timestamps for classes/ML_DAL_ContentVersion.cls:
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   lastDeployedOrRetrievedDate = null
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   serverLastModifiedDate      = Wed Aug 16 16:42:44 SAST 2023
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   localLastModifiedDate       = Thu Aug 17 06:47:11 SAST 2023 (raw)
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   localLastModifiedDate       = Thu Aug 17 06:47:12 SAST 2023 (adjusted)
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Local file newer than server representation: classes/ML_DAL_ContentVersion.cls
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Server file was last modified by a different user (expected 0054J000000uyI4QAI, found 0052500000AhcR4AAJ): classes/ML_DAL_ContentVersion.cls
2023-08-17 06:47:20,329 [168685584]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Server file exists but there is no known last deployment or retrieval date for classes/ML_DAL_ContentVersion.cls
2023-08-17 06:47:21,010 [168686265]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - The following files need to be merged:
2023-08-17 06:47:21,010 [168686265]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - classes/ML_DAL_ContentVersion.cls - last modified by Dave De Buys ([e-mail].t1devy) on Wed Aug 16 16:42:44 SAST 2023

that can be correlated against that previous retrieval. The entries above are from the provided log, but what I don’t know is why the second one doesn’t have a value for lastDeployedOrRetrievedDate which is ultimately what’s leading to the perceived conflict.

It’s also worth confirming which conflict detection strategy you’re using, particularly since I see Server file was last modified by a different user in the log. Are you using Dedicated Logins or Shared Logins, and what is the user access model for this org? Is it just you, or are others also making changes in the org?

Hopefully once I have all of that info, I can determine what’s going on…

[Jason van Beukering]

Hi Scott,

In answer to your questions:

• We are using dedicated logins
• Multiple people are making changes in the org, often to the same artefacts

Once I get a conflict again, I’ll send all the relevant log files

These are the log settings I have enabled

#com.illuminatedcloud.intellij.builder.IlluminatedCloudDeployOnSaveAllActionListener
#com.illuminatedcloud.intellij.builder.IlluminatedCloudSaveAllAction
#com.illuminatedcloud.intellij.builder.ForceComBuilder
#com.illuminatedcloud.intellij.builder.ForceComBuilderUtil
#com.illuminatedcloud.intellij.builder.ForceComMetadataApiDeployer
#com.illuminatedcloud.intellij.builder.ForceComSfdxMetadataDeployer
#com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer
#com.illuminatedcloud.intellij.builder.ForceComSfdxMetadataUtil
#com.illuminatedcloud.intellij.builder.ForceComToolingApiDeployer
#com.illuminatedcloud.intellij.builder.ForceComBuildFailureAnnotator
#com.illuminatedcloud.util.VariableLengthPollingInterval
#com.illuminatedcloud.intellij.builder.RefreshAction
#com.illuminatedcloud.intellij.builder.RetrieveAction
#com.illuminatedcloud.intellij.builder.ForceComBuilder
#com.illuminatedcloud.intellij.builder.ForceComBuilderUtil
#com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever
#com.illuminatedcloud.intellij.builder.ForceComSfdxMetadataRetriever
#com.illuminatedcloud.intellij.builder.ForceComSfdxRetriever
#com.illuminatedcloud.intellij.builder.ForceComSfdxMetadataUtil
#com.illuminatedcloud.intellij.util.IlluminatedCloudDiffUtil
#com.illuminatedcloud.util.VariableLengthPollingInterval

‌

‌

[Scott Wells]

Thanks for the additional details. Yeah, please send over all relevant logs when you reproduce this again ranging from the retrieval to the conflict report and I’ll let you know what I see.

[Jason van Beukering]

Happened again. I got latest files this morning and reporting a conflict for file updated yesterday. This archive has all the log files

[Scott Wells]

Thanks. I believe that shows me what’s happening:

2023-08-31 09:38:21,385 [1295307]   FINE - #com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever - Processing /Users/jason.van.beukering/Library/Caches/JetBrains/WebStorm2023.2/tmp/T1DevY-LibertyT1DevY-retrieve/tmp/unpackaged/classes/SC_CTRL_GuidedInteraction.cls.
2023-08-31 09:38:21,385 [1295307]   FINE - #com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever -   Using filename SC_CTRL_GuidedInteraction.cls.
2023-08-31 09:38:21,386 [1295308]   FINE - #com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever -   No matching existing file found.
2023-08-31 09:38:21,386 [1295308]   FINE - #com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever -   Placing in source root src.
2023-08-31 09:38:21,386 [1295308]   FINE - #com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever -   Moving/copying /Users/jason.van.beukering/Library/Caches/JetBrains/WebStorm2023.2/tmp/T1DevY-LibertyT1DevY-retrieve/tmp/unpackaged/classes/SC_CTRL_GuidedInteraction.cls to /Users/jason.van.beukering/Library/Caches/JetBrains/WebStorm2023.2/tmp/T1DevY-LibertyT1DevY-retrieve/diff/src/classes as SC_CTRL_GuidedInteraction.cls.
2023-08-31 09:39:25,007 [1358929]   INFO - #com.illuminatedcloud.intellij.builder.ForceComMetadataRetriever - Populated /Users/jason.van.beukering/Documents/_work/_dev/repos/liberty/T1DevY/src/classes/SC_CTRL_GuidedInteraction.cls.
...
2023-08-31 10:01:52,233 [2706155]   FINE - #com.illuminatedcloud.intellij.builder.ForceComToolingApiDeployer - Using the tooling API to deploy the following files for module T1DevY: { SC_CTRL_GuidedInteraction.cls }.
2023-08-31 10:01:52,233 [2706155]   FINE - #com.illuminatedcloud.intellij.builder.ForceComToolingApiDeployer - Checking for conflicts.
2023-08-31 10:02:08,965 [2722887]   INFO - #com.illuminatedcloud.intellij.configCache.FilePropertiesCache - Enumerated metadata for connection LibertyT1DevY in 16 s 718 ms.
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Comparing local to server timestamps for classes/SC_CTRL_GuidedInteraction.cls:
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   lastDeployedOrRetrievedDate = null
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   serverLastModifiedDate      = Wed Aug 30 16:11:12 SAST 2023
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   localLastModifiedDate       = Thu Aug 31 10:01:52 SAST 2023 (raw)
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   localLastModifiedDate       = Thu Aug 31 10:01:52 SAST 2023 (adjusted)
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Local file newer than server representation: classes/SC_CTRL_GuidedInteraction.cls
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Server file was last modified by a different user (expected 0054J000000uyI4QAI, found 0052500000BCRfUAAX): classes/SC_CTRL_GuidedInteraction.cls
2023-08-31 10:02:08,982 [2722904]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Server file exists but there is no known last deployment or retrieval date for classes/SC_CTRL_GuidedInteraction.cls
2023-08-31 10:02:09,675 [2723597]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - The following files need to be merged:
2023-08-31 10:02:09,676 [2723598]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - classes/SC_CTRL_GuidedInteraction.cls - last modified by Abhishek Bisht ([e-mail].t1devy) on Wed Aug 30 16:11:12 SAST 2023
2023-08-31 10:02:09,676 [2723598]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder - Validating conflict information.
2023-08-31 10:02:09,676 [2723598]   FINE - #com.illuminatedcloud.intellij.builder.ForceComBuilder -   Conflicts were detected.

Obviously there was a retrieval at 9:38AM, and when you deployed at 10:02AM, it detected a conflict because it didn’t have a value for lastDeployedOrRetrievedDate and instead incorrectly saw the last server modification by another user.

So, it seems that there’s some retrieval path where either the value for lastDeployedOrRetrievedDate is not being updated, or it’s being updated using a key that isn’t the same one used later for retrieval. Hopefully that should give me enough for a local reproduction and subsequent fix.

Thanks for providing the logs!

[Scott Wells]

How are you initiating the retrieval here? Are you doing it using the Compare with Server action or the Retrieve action? The former doesn’t update the values used for lastDeployOrRetrievedDate as it’s typically intended to be used for comparing server vs. local whereas the latter does update them as it’s intended to be used for merging into local or even direct population of local.

I could be barking up the wrong tree, but that’s the only situation I’m seeing where IC2 doesn’t set those values. I’m curious to get the exact steps that were followed resulting in the log you provided so that I can ensure that I’m doing the exact same thing. Thanks!

[Scott Wells]

Resolving due to lack of activity. If this is still an issue, please feel free to reproduce with new diagnostic information and/or concrete steps to reproduce.