microsoft / sql-server-language-extensions

language-extensions-sqlserver
Other
106 stars 42 forks source link

SQL Server Linux: JavaExtension -> Reduce minimum SPEES execution time down from 5 seconds. #50

Closed seantleonard closed 2 months ago

seantleonard commented 2 months ago

Why this change

What is this change

Sample Execution logs using Debug Build. As printed by SQL Server in SSMS

Demonstrating Start Time: 2024-04-09 00:20:12.24 Completion time: 2024-04-08T17:20:12.4804303-07:00 ~< 1 second execution time.

Sample Execution of custom Java function which outputs the status of all threads: image

STDOUT message(s) from external script: 2024-04-09 00:20:12.24 JavaExtension::Init 2024-04-09 00:20:12.24 Successfully loaded JVM from path: /usr/lib/jvm/java-17-openjdk-amd64/lib/server/libjvm.so 2024-04-09 00:20:12.24 CLASSPATH=/home/mssql_satellite/externallibrariessandboxpublicpath/sdk:/home/mssql_satellite/externallibrariessandboxpublicpath/regexsleeper JProfiler> Protocol version 66 JProfiler> Java 17 detected. JProfiler> Don't wait for frontend to connect. JProfiler> 64-bit library JProfiler> Starting up without initial configuration. JProfiler> Listening on port: 8849. JProfiler> Enabling native methods instrumentation. JProfiler> Can retransform classes. JProfiler> Can retransform any class. JProfiler> Native library initialized JProfiler> VM initialized JProfiler> Retransforming 6 base class files. JProfiler> Base classes instrumented. 2024-04-09 00:20:12.44 JVM load succeeded: Version 10.0. 2024-04-09 00:20:12.44 JavaExtension::InitSession 2024-04-09 00:20:12.44 Starting session: 08246ED2-F3E7-4102-B7F0-2D4E2E8841E0 with task id: 0. 202 STDOUT message(s) from external script: 4-04-09 00:20:12.44 JavaSession::CallUserInit 2024-04-09 00:20:12.44 JavaExtension::InitColumn 2024-04-09 00:20:12.44 Initializing column #0 2024-04-09 00:20:12.44 JavaExtension::InitColumn 2024-04-09 00:20:12.44 Initializing column #1 2024-04-09 00:20:12.44 JavaExtension::InitParam 2024-04-09 00:20:12.44 Initializing input parameter #0 2024-04-09 00:20:12.44 JavaExtension::Execute 2024-04-09 00:20:12.44 JavaSession::ExecuteWorkflow 2024-04-09 00:20:12.44 JavaSession::CallUserExecute 2024-04-09 00:20:12.44 JavaDataset::Init 2024-04-09 00:20:12.44 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.44 JavaDataset::AddColumns 2024-04-09 00:20:12.44 JavaDataset::AddColumnMetadata 2024-04-09 00:20:12.44 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.44 JavaDataset::AddColumn 2024-04-09 00:20:12.45 JavaDataset::AddColumnInternal 2024-04-09 00:20:12.45 JavaDataset::FindAddColumnMethod 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::AddColumnMetadata 2024-04-09 00:20:12. STDOUT message(s) from external script: 45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::AddColumn 2024-04-09 00:20:12.45 JavaDataset::AddStringColumnInternal 2024-04-09 00:20:12.45 JavaDataset::FindAddColumnMethod 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod Non-daemon threads: 2024-04-09 00:20:12.45 JavaDataset::Init 2024-04-09 00:20:12.45 JavaDataset::GetColumns 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetColumn 2024-04-09 00:20:12.45 JavaDataset::GetColumnType 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetStringColumnInternal 2024-04-09 00:20:12.45 JavaDataset::FindGetColumnMethod 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::CalculateMaxForVarLengthOutputData 2024-04-09 00:20:12.45 JavaDataset::GetColumn 2024-04-09 00:20:12.45 JavaDataset::GetColumnType 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetColumnInternal 2024-04-09 00:20 STDOUT message(s) from external script: :12.45 JavaDataset::FindGetColumnMethod 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetColumnNullMap 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetColumn 2024-04-09 00:20:12.45 JavaDataset::GetColumnType 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetColumnInternal 2024-04-09 00:20:12.45 JavaDataset::FindGetColumnMethod 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaDataset::GetColumnNullMap 2024-04-09 00:20:12.45 JavaDataset::FindDatasetMethod 2024-04-09 00:20:12.45 JavaExtension::GetResultColumn 2024-04-09 00:20:12.45 Retrieving metadata for result column #0 2024-04-09 00:20:12.45 JavaExtension::GetResultColumn 2024-04-09 00:20:12.45 Retrieving metadata for result column #1 2024-04-09 00:20:12.45 JavaExtension::GetResultColumn 2024-04-09 00:20:12.45 Retrieving metadata for result column #2 2024-04-09 00:20:12.45 JavaExtension::GetResult STDOUT message(s) from external script: s 2024-04-09 00:20:12.45 JavaSession::GetResults 2024-04-09 00:20:12.45 JavaExtension::CleanupSession 2024-04-09 00:20:12.45 JavaSession::Cleanup 2024-04-09 00:20:12.45 JavaSession::CallUserCleanup 2024-04-09 00:20:12.45 Cleaning up input arg #0 2024-04-09 00:20:12.45 Calling cleanup 2024-04-09 00:20:12.45 Cleaning up JVM

(7 rows affected)

Completion time: 2024-04-08T17:20:12.4804303-07:00

SicongLiu2000 commented 2 months ago

Please remove outdated PR desc: Updates the Linux build scripts to use tar to create the extension output as tar preserves Linux file attributes/permissions versus using "Zip".

seantleonard commented 2 months ago

Please remove outdated PR desc: Updates the Linux build scripts to use tar to create the extension output as tar preserves Linux file attributes/permissions versus using "Zip".

Done, thanks!

Aniruddh25 commented 2 months ago

In description, could you provide example of how long it used to take BEFORE this change?

seantleonard commented 2 months ago
  • SQL Server Linux had a minimum 5 second execution time for SPEES

Do you mean for the example query i illustrated? or in general? In general, i had this at the beginning of the pr description: "SQL Server Linux had a minimum 5 second execution time for SPEES "