andygrove commented on issue #1098: URL: https://github.com/apache/datafusion-comet/issues/1098#issuecomment-2486453783
This is getting pretty interesting. I improved the native explain feature in https://github.com/apache/datafusion-comet/pull/1099 and we now see the planning time. The following trivial plan takes more than a second to plan. ``` 24/11/19 11:25:26 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.304405241s): ShuffleWriterExec: partitioning=UnknownPartitioning(1) ScanExec: source=[], schema=[col_0: Int64, col_1: Decimal128(34, 4), col_2: Date32, col_3: Int32] ``` I also added a criterion benchmark to plan this query in the same PR, and it only takes 23 *microseconds*. Another observation is that the planning time increases each time: ``` 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.377855944s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.403194796s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.424167789s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.487451934s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.492228413s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.517392898s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.534502296s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.556645236s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.622664488s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.622664287s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.730488921s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.730601884s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.730662237s): 24/11/19 11:25:24 INFO core/src/execution/jni_api.rs: Comet native query plan (planning took 1.73067477s): ``` Something strange is happening here. Does this indicate that some sort of contention or locking is happening which is resulting in these long times? -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
