SQL Server: "Flushing unhandled packet from the wire. Please consume your streams!"

[janpio]

See DEBUG=* log output at #7476 (comment):

prisma:query SELECT [dbo].[people_List].[id_People], [dbo].[people_List].[Surname], [dbo].[people_List].[Name], [dbo].[people_List].[Patronymic], [dbo].[people_List].[OldSurname], [dbo].[people_List].[OldName], [dbo].[people_List].[OldPatronymic], [dbo].[people_List].[Marriage], [dbo].[people_List].[Sex], [dbo].[people_List].[BornDate], [dbo].[people_List].[BornPlace], [dbo].[people_List].[id_Doc], [dbo].[people_List].[DocSerial], [dbo].[people_List].[DocNo], [dbo].[people_List].[DocDistributed], [dbo].[people_List].[DocDate], [dbo].[people_List].[DocDepartmentCode], [dbo].[people_List].[id_Sitizen], [dbo].[people_List].[Photo], [dbo].[people_List].[Other], [dbo].[people_List].[is_webimported], [dbo].[people_List].[id_web], [dbo].[people_List].[FIO], [dbo].[people_List].[FIO2], [dbo].[people_List].[msrepl_tran_version], [dbo].[people_List].[SurnameRP], [dbo].[people_List].[NameRP], [dbo].[people_List].[PatronymicRP], [dbo].[people_List].[id_Nationality_old], [dbo].[people_List].[id_Nationality], [dbo].[people_List].[UID], [dbo].[people_List].[UID_stat], [dbo].[people_List].[UID_sok], [dbo].[people_List].[UID_zo], [dbo].[people_List].[INN_old], [dbo].[people_List].[SSN], [dbo].[people_List].[INN], [dbo].[people_List].[tabNumber] FROM [dbo].[people_List] WHERE 1=1
  prisma:engine stdout Fetched a connection from the pool +1ms
  prisma:engine stdout Flushing unhandled packet from the wire. Please consume your streams! +0ms
prisma:warn Flushing unhandled packet from the wire. Please consume your streams!
  prisma:engine stdout Flushing unhandled packet from the wire. Please consume your streams! +1ms
prisma:warn Flushing unhandled packet from the wire. Please consume your streams!
  prisma:engine stdout Flushing unhandled packet from the wire. Please consume your streams! +1ms
prisma:warn Flushing unhandled packet from the wire. Please consume your streams!
  prisma:engine {

Related code: https://github.com/prisma/tiberius/blob/56d3b482be9ad17d2472382713c55af4afe32ce2/src/client/connection.rs#L191

[tomhoule]

@pimeys could it be the fabled cancellation problem?

[pimeys]

It's not really a problem if the connection doesn't break and turn unusable. If we only get these warnings, the system works as designed.

Or, this is an issue where we read only one row and do not consume what is left in the wire. I doubt we have code like that anywhere.

The problem this warning causes is that before running another query, we must flush the old data from the stream. So you share a bit of throughput between queries.

[pimeys]

So, as I explained in the other ticket, the warnings are not a problem, handling of some weird collation from non-utf columns is.

[pantharshit00]

Since #7476 is closed, @pimeys we can close this as well?

[janpio]

Please change the warning to something that tells users to report this as an issue and does not require me or anyone else to accidentally notice it via another issue. Thanks.

[janpio]

Notes from internal discussion: The log message is from tiberius, and only happens when we (as tiberius users) did not implement something properly - which was the case above because of a bug we had. In theory this could happen again in the future though, and then again our logs would have this tiberius log without any context. Even if the tiberius log is modified to include a link to create an issue etc, this will be pretty confusing.

A "solution" we talked about was to prefix the log messages with where they were coming from in the log output.

[thebiglabasky]

After discussing it with the team we landed on it being not GA-blocking material although something we should indeed fix.