11

3-30-2017 Just got a call from sf tier one wanting me to show them how to replicate the issue SMH. They then point me to the dev forums and closed the case ugh


We are seeing multiple customers having issues with external systems logging transactions from Salesforce IP's during times when there are no batch processes running in salesforce.

Background

  1. Daily batch that sends records to an external system
  2. Batch runs without issue daily starting at 2AM
  3. Batch takes on average 5-10 to complete

We are seeing within the last week or so customers complaining that duplicate transactions are occurring daily

Several of these customer have been running the same version of our software for over 5 years without any issues. No org changes have occurred (not sure of a split). nothing shows up in audit trail. Same records have been sent on a routine basis to the external system (monthly/annually) without change. It just started happening out of the blue

Heuristics

  1. Duplicate timestamps are varying times (i.e. 4:23AM, 5:31AM)
  2. NO batch processes are running in the org at the time
  3. Some customers have Full Sandboxes, some do not
  4. Ids sent to the external system match an Id of a record in the production org
  5. No timestamps in that timeframe exist on the records
  6. Our error logging does not log anything
  7. No records indicating the communication took place are created

Summary

We can find nothing that is running in the orgs that would be sending the records to the external system. Given some customers do not have full sandboxes, I ruled out the possibility fo the process be ran from a sandbox by mistake. Either way, the timestamps would suggest that not be the case as well

Question

  • Is anyone else seeing this behavior?
  • Is it possible that there is a critical issue where shadow processes are being run for whatever reason by SF? Maybe an org split causing things to go haywire?

I know this is a bit broad and subjective, etc but I would really appreciate if anyone that may have seen something similar chime in. Trying to put this in as a support ticket to SF would be, well, I would rather get married again, poke my eye with glass, pull all my fingernails off, you get the point.

I have never ran into anything like this in the last 7 years working on the platform and I am at a complete loss. My only hope is to find others that have seen a similar thing occurring in the last week or so

Any suggestions on troubleshooting (other than contacting SF support) or if you have seen anything similar would be helpful.....

13
  • 6
    You'd rather get married again than submit a support ticket?!
    – sfdcfox
    Commented Mar 23, 2017 at 21:27
  • 2
    @sfdcfox - for this issue yes, I believe it would be the lesser of two evils...The process leave a lot to be desired IMHO......All in good fun of course.
    – Eric
    Commented Mar 23, 2017 at 21:39
  • "Batch takes on average 5-10 to complete". Seconds/Minutes/Hours/Iterations? Not sure it really matters which, just trying to clarify. Commented Mar 27, 2017 at 19:52
  • 1
    I assume the batch is making a Callout to the external system. Do you have access to the Apex Callout EventLogFile? I know it would be a paid feature, but it might show you when the duplicate callouts are occurring. Commented Mar 27, 2017 at 19:54
  • Are there any Outbound Messages involved in the Callout process where an inital NACK response or timeout could cause the request to be retried. Commented Mar 27, 2017 at 19:55

4 Answers 4

8
+100

Not sure this is worthy of an answer, but too much to put as a comment. The only time I have seen anything remotely similar was with this and I was able to prove to support that a job had run and created duplicates.

The info I got back from Tier 3 at the time:

As we discussed, during the execution, an internal server error on the asynchronous process for the batch, resulted in cloned message in the asynchronous queue to not be removed resulting in duplicate messages getting worked. As a result of unlucky timing when an exception is thrown, this may result in cloned messages not being deleted and actually executed in parallel to actual messages

A Bug has been logged to fix this issue from Salesforce end.

It is scheduled in patch release next week.

'Last week' was just over 2 years ago. I can share my case # if you wish. The case status is currently: Closed - Bug Fix Submitted

Worth noting our customer stopped using our app ~6 months after but I never saw a re-occurrence in that time. It would also have been an EUn pod.

Good luck.

2
  • 1
    Thanks for the info. Any answer right now is good. i am attempting to gather all the information I can before I attempt to submit a case. The only proof I have at the moment is the absence of proof lol. We currently have 3-4 customer reporting this with similar heuristics. the other 400+ customers are not reporting anything (yet). The only common thread is that there is no process running in their orgs at the time and the timestamps in external system do not match with any scenario I can come up with that could cause it
    – Eric
    Commented Mar 27, 2017 at 14:45
  • Looking at the case notes, I also had access to Apex logs that showed 'First error: connection was cancelled here’ so I guess they were obliged to investigate that in the first instance. Commented Mar 27, 2017 at 14:48
8

Seems I got some attention after submitting a case or this post or whatever, just got this notification: A bit late but at least I know the cause

On March 16, 2017, Salesforce identified a misconfiguration in our test environment that allowed Apex callouts and outbound messages to reach endpoints outside of the test environment. At the same time, these Apex callouts and outbound messages were being executed, as expected, in your production environment. The simultaneous execution of callouts and messages from both environments may have resulted in duplicate or unexpected results. The issue was resolved at approximately 5:30 p.m. PDT on March 16, 2017. However, the fix did not correct the duplicate or unexpected results from Apex callouts and outbound messages that occurred as early as February 28 through March 16, 2017.

We have identified that your org is associated with Apex callouts and/or outbound messages that executed in the testing environment between February 28 and March 16, 2017. However, we are unable to confirm if these jobs produced duplicate or unexpected results as they are customized to your implementation.

2
  • Unfortunately, it looks like you may have to submit a support ticket to resolve this. Um... enjoy booking a D.J.! Commented Mar 30, 2017 at 16:53
  • @CharlesKoppelman - Ha! Going to let it be. Their acknowledgement of the issue takes the burden off of us. Client can submit a ticket if they need to....
    – Eric
    Commented Mar 30, 2017 at 16:54
4

This just in from SF:

On March 16, 2017, Salesforce identified a misconfiguration in our test environment that allowed Apex callouts and outbound messages to reach endpoints outside of the test environment. At the same time, these Apex callouts and outbound messages were being executed, as expected, in your production environment. The simultaneous execution of callouts and messages from both environments may have resulted in duplicate or unexpected results. The issue was resolved at approximately 5:30 p.m. PDT on March 16, 2017. However, the fix did not correct the duplicate or unexpected results from Apex callouts and outbound messages that occurred as early as February 28 through March 16, 2017.

We have identified that your org is associated with Apex callouts and/or outbound messages that executed in the testing environment between February 28 and March 16, 2017. However, we are unable to confirm if these jobs produced duplicate or unexpected results as they are customized to your implementation.

Which sounds like it could have just the results that you were seeing!

3

It seems possible these duplicate callouts may have been related to Hammer Testing. Our CSM didn't give us any dates but reached out to us proactively. Relevant communication:

Summary:
Our internal functional testing environments, known as “hammer tests,” were unexpectedly performing customer scheduled Apex job callouts to external endpoints through outbound proxies due to a configuration in our "hammer" environment. This resulted in the processing of some customers’ Apex scheduled batch jobs that were present in the hammer test copy of production. As part of the current hammer test run, a CRON job scheduler process was enabled, which had not been used in previous hammer tests. When the CRON job scheduler was enabled, the scheduler began processing scheduled Apex jobs that were present in the hammer environment. As these Apex jobs started getting executed, they initiated callouts to external endpoints via outbound proxies. These unexpected API callout activities caused hammer test environments and production to process the same scheduled jobs and could have resulted in duplicate or unexpected results which will need to be investigated by someone familiar with the callouts/processes on the customer side.

Preventive Actions:
Internal hammer testing environments across all Salesforce instances were shut down to prevent any additional Apex jobs from running in the hammer test environment. The engineering team is investigating options to provide greater isolation of the hammer test environment from external endpoints in order to prevent them from making any outbound calls in the future. Additionally, the CRON job scheduler will not be enabled in hammer test environment going forward.

1
  • Nice. Only a million or so in double charges performed across our clients and their customers. No big deal.....15 days to notify..acceptable.....Oh my....This screw up by SF is a BFD and it seems they are just saying, oops....sorry bout that
    – Eric
    Commented Mar 30, 2017 at 19:17

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .