[
https://issues.apache.org/jira/browse/HIVE-29008?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17978628#comment-17978628
]
Stamatis Zampetakis commented on HIVE-29008:
--------------------------------------------
As expected the extra logs do not affect the execution time of the tests. To
confirm it suffices to compare the inspect the test reports for the PR run and
latest master:
* PR-5862:
https://ci.hive.apache.org/job/hive-precommit/job/PR-5862/2/testReport/junit/api/json
* master build#2554:
https://ci.hive.apache.org/job/hive-precommit/job/master/2554/testReport/api/json
For reference purposes the test reports are compressed and attached:
[^master2554_testReport.json.gz] [^pr5862_testReport.json.gz]
{noformat}
$ jq .duration master2554_testReport.json
100193.016
$ jq .duration pr5862_testReport.json
95438.56
{noformat}
The build time is not affected either from the extra logs. To verify this
someone can check the execution time of each individual pipeline step in the
Blue Ocean UI or download the full execution log
(https://ci.hive.apache.org/job/hive-precommit/job/PR-5862/2/consoleText) and
check the total execution time.
{noformat}
$ grep "Total time" pr5862-2-consoleText.txt
[2025-06-13T17:41:47.449Z] [INFO] Total time: 01:58 min
[2025-06-13T18:13:04.585Z] [INFO] Total time: 31:07 min
[2025-06-13T18:29:06.124Z] [INFO] Total time: 22.860 s
[2025-06-13T18:29:15.649Z] [INFO] Total time: 5.421 s
[2025-06-13T18:29:24.637Z] [INFO] Total time: 5.488 s
[2025-06-13T18:48:12.204Z] [INFO] Total time: 18:41 min
[2025-06-13T18:51:42.510Z] [INFO] Total time: 23:05 min
[2025-06-13T19:20:11.222Z] [INFO] Total time: 31:48 min
[2025-06-13T19:41:58.176Z] [INFO] Total time: 01:11 h
[2025-06-13T19:43:28.243Z] [INFO] Total time: 01:12 h
[2025-06-13T19:43:46.660Z] [INFO] Total time: 01:14 h
[2025-06-13T19:44:56.534Z] [INFO] Total time: 01:16 h
[2025-06-13T19:48:01.182Z] [INFO] Total time: 01:18 h
[2025-06-13T19:49:57.870Z] [INFO] Total time: 01:13 h
[2025-06-13T19:54:55.105Z] [INFO] Total time: 01:19 h
[2025-06-13T19:56:14.505Z] [INFO] Total time: 01:25 h
[2025-06-13T19:58:33.244Z] [INFO] Total time: 01:15 h
[2025-06-13T20:07:13.327Z] [INFO] Total time: 01:23 h
[2025-06-13T20:09:42.089Z] [INFO] Total time: 01:25 h
[2025-06-13T20:43:17.105Z] [INFO] Total time: 01:19 h
[2025-06-13T20:44:02.681Z] [INFO] Total time: 01:21 h
[2025-06-13T20:46:16.522Z] [INFO] Total time: 01:04 h
[2025-06-13T20:47:44.000Z] [INFO] Total time: 01:14 h
[2025-06-13T20:52:17.579Z] [INFO] Total time: 01:15 h
[2025-06-13T20:54:05.727Z] [INFO] Total time: 01:12 h
[2025-06-13T20:55:06.791Z] [INFO] Total time: 01:11 h
[2025-06-13T20:56:14.700Z] [INFO] Total time: 01:20 h
[2025-06-13T20:58:07.742Z] [INFO] Total time: 01:16 h
[2025-06-13T21:02:24.482Z] [INFO] Total time: 01:22 h
[2025-06-13T21:03:44.435Z] [INFO] Total time: 01:20 h
[2025-06-13T21:42:36.869Z] [INFO] Total time: 02:49 h
{noformat}
The execution time for each pipeline step running the tests is ~01:20 h, which
is more or less the same with master.
Finally, the extra logs (removal of the quiet mode) lead to a 20% increase of
the storage space required for saving the full log file:
* https://ci.hive.apache.org/job/hive-precommit/job/master/2554/consoleText
* https://ci.hive.apache.org/job/hive-precommit/job/PR-5862/2/consoleText
{noformat}
ls -lh *txt
-rw-rw-r-- 1 zabetak zabetak 25M Jun 16 10:18 master_2554_consoleText.txt
-rw-rw-r-- 1 zabetak zabetak 30M Jun 16 10:02 pr5862-2-consoleText.txt
{noformat}
Although the 20% increase may appear significant, in practice we are just
talking about 5MB more per run that I feel is worth paying for the extra aid in
diagnosing problems in CI.
> CI logs do not display information about test execution
> -------------------------------------------------------
>
> Key: HIVE-29008
> URL: https://issues.apache.org/jira/browse/HIVE-29008
> Project: Hive
> Issue Type: Bug
> Components: Build Infrastructure, Testing Infrastructure
> Reporter: Stamatis Zampetakis
> Assignee: Stamatis Zampetakis
> Priority: Major
> Labels: pull-request-available
> Attachments: master2554_testReport.json.gz, pr5862_testReport.json.gz
>
>
> Locally, when we run tests via maven we usually see the following INFO
> messages in the console.
> {noformat}
> [INFO] -------------------------------------------------------
> [INFO] T E S T S
> [INFO] -------------------------------------------------------
> [INFO] Running org.apache.hadoop.hive.ql.exec.vector.TestDateColumnVector
> [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.198
> s -- in org.apache.hadoop.hive.ql.exec.vector.TestDateColumnVector
> [INFO]
> [INFO] Results:
> [INFO]
> [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0
> [INFO]
> {noformat}
> The output is very useful for various reasons and in particular to know the
> status of the current test that is running. This is even more important in CI
> where intermittent failures may arise since we want an easy way to determine
> which test was run at each point in time.
> In the [past|https://ci.hive.apache.org/job/hive-precommit/job/master/2334/],
> this information was present in every CI run and we could easily see the test
> that is currently running in each split. However, after upgrading the
> maven-surefire-plugin to 3.5.1 (HIVE-28519) this information was lost and is
> not present in the CI output/logs
> [anymore|https://ci.hive.apache.org/job/hive-precommit/job/master/2548/].
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
