Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DateTimeOffsetAllScalesTestShouldSucceed Test failures (Values Differ / Ticks must be between Min/Max) #3011

Closed
MichelZ opened this issue Nov 18, 2024 · 7 comments
Labels
🆕 Triage Needed For new issues, not triaged yet.

Comments

@MichelZ
Copy link
Contributor

MichelZ commented Nov 18, 2024

I have seen failures of this test:
DateTimeOffsetAllScalesTestShouldSucceed

You can see one instance here:
https://sqlclientdrivers.visualstudio.com/public/_build/results?buildId=101821&view=logs&j=29d1df32-80c6-5ba5-e9d6-57c8659715f0&t=4b5dd44d-d567-5ef9-1055-7c665b22b01c&l=1162

I have added logging and did "Run until failure", it takes a few passes (sometimes 20, sometimes 200+) to fail, but it does fail with these errors:

Message: 
Assert.Equal() Failure: Values differ
Expected: 2024-01-01T23:59:59.0100000+00:00
Actual:   2024-01-10T23:59:50.1000000+00:00

Standard Output: 
2024-11-18T08:49:48.8893352Z: Failed for scale 2 DateTimeOffset: 1/1/2024 11:59:59 PM +00:00 Result: 1/10/2024 11:59:50 PM +00:00

Then there's also this one:

Message: 
System.ArgumentOutOfRangeException : Ticks must be between DateTime.MinValue.Ticks and DateTime.MaxValue.Ticks. (Parameter 'ticks')

Stack Trace: 
DateTime.ThrowTicksOutOfRange()
DateTimeOffset.ctor(Int64 ticks, TimeSpan offset)
SqlBuffer.get_DateTimeOffset() line 641
SqlBuffer.get_Value() line 1092
SqlDataReader.GetValueFromSqlBufferInternal(SqlBuffer data, _SqlMetaData metaData) line 2842
SqlDataReader.GetValueInternal(Int32 i) line 2812
SqlDataReader.GetValue(Int32 i) line 2746
SqlCommand.CompleteExecuteScalar(SqlDataReader ds, Boolean returnLastResult) line 1174
SqlCommand.ExecuteScalar() line 1143
UdtDateTimeOffsetTest.DateTimeOffsetAllScalesTestShouldSucceed() line 120
RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

Standard Output: 
2024-11-18T09:14:32.2074816Z: Failed for scale 5 DateTimeOffset: 1/1/2024 11:59:59 PM +00:00 Result: No result

Now I'm not sure if it's the test's fault, or if there is something wrong in the MDS code...
I'm adding it as an issue for tracking purposes

Code with added logging:

// This unit test is to ensure that time in DateTimeOffset with all scales are working as expected
[ConditionalFact(typeof(DataTestUtility), nameof(DataTestUtility.AreConnStringsSetup), nameof(DataTestUtility.IsNotAzureServer), nameof(DataTestUtility.IsNotAzureSynapse))]
public void DateTimeOffsetAllScalesTestShouldSucceed()
{
    string tvpTypeName = DataTestUtility.GetUniqueNameForSqlServer("tvpType");

    using SqlConnection connection = new(_connectionString);
    connection.Open();

    try
    {
        // Use different scale for each test: 0 to 7
        int fromScale = 0;
        int toScale = 7;

        for (int scale = fromScale; scale <= toScale; scale++)
        {
            DateTimeOffset dateTimeOffset = new DateTimeOffset(2024, 1, 1, 23, 59, 59, TimeSpan.Zero);

            // Add sub-second offset corresponding to the scale being tested
            TimeSpan subSeconds = TimeSpan.FromTicks((long)(TimeSpan.TicksPerSecond / Math.Pow(10, scale)));
            dateTimeOffset = dateTimeOffset.Add(subSeconds);

            DataTestUtility.DropUserDefinedType(connection, tvpTypeName);
            SetupDateTimeOffsetTableType(connection, tvpTypeName, scale);

            var param = new SqlParameter
            {
                ParameterName = "@params",
                SqlDbType = SqlDbType.Structured,
                Scale = (byte)scale,
                TypeName = $"dbo.{tvpTypeName}",
                Value = new DateTimeOffsetVariableScale[] { new DateTimeOffsetVariableScale(dateTimeOffset, scale) }
            };

            using (var cmd = connection.CreateCommand())
            {
                cmd.CommandText = "SELECT * FROM @params";
                cmd.Parameters.Add(param);
                 object result = null;
                 try
                 {
                     result = cmd.ExecuteScalar();
                     Assert.Equal(dateTimeOffset, result);
                 }
                 catch (Exception)
                 {
                     _testOutputHelper.WriteLine($"{DateTime.UtcNow:O}: Failed for scale {scale} DateTimeOffset: {dateTimeOffset} Result: {result ?? "No result"}");
                     throw;
                 }
            }
        }
    }
    finally
    {
        DataTestUtility.DropUserDefinedType(connection, tvpTypeName);
    }
}
@vonzshik
Copy link

Taking a quick look, this seems to be SQLServer bug (yet another one, hooray!).
As an example, according to wireshark, at one moment we send DateTimeOffset with a length of 9 (the first byte): 09 19 58 26 05 45 46 0b 00 00

Image

Yet what we get is DateTimeOffset with a length of 8: 08 19 58 26 05 45 46 0b 00

Image

My guess is, because the test reuses the name for udt, SQLServer becomes slightly confused and sometimes reuses types even though they were recreated with a different scale.
You should be able to confirm this by making it so the test creates a unique udt for each scale.

@vonzshik
Copy link

Unrelated to the issue, but might as well mention it here. While trying to debug I've encountered that this assert is always failing

Debug.Assert(synonyms.Count == count, "incorrect initial ParseSynonyms size");

@MichelZ
Copy link
Contributor Author

MichelZ commented Nov 18, 2024

Unrelated to the issue, but might as well mention it here. While trying to debug I've encountered that this assert is always failing

SqlClient/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlConnectionString.cs

Line 861 in b1f7eaf
Debug.Assert(synonyms.Count == count, "incorrect initial ParseSynonyms size");

Yes, I've encountered this as well, but I'm not sure what's wrong currently... :)

@MichelZ
Copy link
Contributor Author

MichelZ commented Nov 18, 2024

Taking a quick look, this seems to be SQLServer bug (yet another one, hooray!). As an example, according to wireshark, at one moment we send DateTimeOffset with a length of 9 (the first byte): 09 19 58 26 05 45 46 0b 00 00

Image

Yet what we get is DateTimeOffset with a length of 8: 08 19 58 26 05 45 46 0b 00

Image

My guess is, because the test reuses the name for udt, SQLServer becomes slightly confused and sometimes reuses types even though they were recreated with a different scale. You should be able to confirm this by making it so the test creates a unique udt for each scale.

Thanks. I ran 1000 passes now without issue with unique type per scale 👍 Thanks!

MichelZ added a commit to MichelZ/SqlClient that referenced this issue Nov 18, 2024
MichelZ added a commit to MichelZ/SqlClient that referenced this issue Nov 18, 2024
@MichelZ
Copy link
Contributor Author

MichelZ commented Nov 18, 2024

Unrelated to the issue, but might as well mention it here. While trying to debug I've encountered that this assert is always failing

SqlClient/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlConnectionString.cs

Line 861 in b1f7eaf
Debug.Assert(synonyms.Count == count, "incorrect initial ParseSynonyms size");

An issue has been filed
#3016

@David-Engel
Copy link
Contributor

Oh yeah, this rings a bell. It's arguably a bug in the server's metadata cache. I've seen it when reusing table names with encrypted columns. If you re-use the same name for a different type, it may return the previously cached metadata and result in unexpected behavior. Nice find!

@cheenamalhotra cheenamalhotra added the 🆕 Triage Needed For new issues, not triaged yet. label Nov 18, 2024
cheenamalhotra pushed a commit that referenced this issue Nov 18, 2024
@MichelZ
Copy link
Contributor Author

MichelZ commented Nov 19, 2024

Fixed by PR #3013

@MichelZ MichelZ closed this as completed Nov 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🆕 Triage Needed For new issues, not triaged yet.
Projects
None yet
Development

No branches or pull requests

4 participants