You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@nifi.apache.org by "dan-s1 (via GitHub)" <gi...@apache.org> on 2026/01/30 17:33:39 UTC

[PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

dan-s1 opened a new pull request, #10836:
URL: https://github.com/apache/nifi/pull/10836

   <!-- Licensed to the Apache Software Foundation (ASF) under one or more -->
   <!-- contributor license agreements.  See the NOTICE file distributed with -->
   <!-- this work for additional information regarding copyright ownership. -->
   <!-- The ASF licenses this file to You under the Apache License, Version 2.0 -->
   <!-- (the "License"); you may not use this file except in compliance with -->
   <!-- the License.  You may obtain a copy of the License at -->
   <!--     http://www.apache.org/licenses/LICENSE-2.0 -->
   <!-- Unless required by applicable law or agreed to in writing, software -->
   <!-- distributed under the License is distributed on an "AS IS" BASIS, -->
   <!-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -->
   <!-- See the License for the specific language governing permissions and -->
   <!-- limitations under the License. -->
   
   # Summary
   
   [NIFI-15531](https://issues.apache.org/jira/browse/NIFI-15531)
   
   # Tracking
   
   Please complete the following tracking steps prior to pull request creation.
   
   ### Issue Tracking
   
   - [ ] [Apache NiFi Jira](https://issues.apache.org/jira/browse/NIFI) issue created
   
   ### Pull Request Tracking
   
   - [ ] Pull Request title starts with Apache NiFi Jira issue number, such as `NIFI-00000`
   - [ ] Pull Request commit message starts with Apache NiFi Jira issue number, as such `NIFI-00000`
   - [ ] Pull request contains [commits signed](https://docs.github.com/en/authentication/managing-commit-signature-verification/signing-commits) with a registered key indicating `Verified` status
   
   ### Pull Request Formatting
   
   - [ ] Pull Request based on current revision of the `main` branch
   - [ ] Pull Request refers to a feature branch with one commit containing changes
   
   # Verification
   
   Please indicate the verification steps performed prior to pull request creation.
   
   ### Build
   
   - [ ] Build completed using `./mvnw clean install -P contrib-check`
     - [ ] JDK 21
     - [ ] JDK 25
   
   ### Licensing
   
   - [ ] New dependencies are compatible with the [Apache License 2.0](https://apache.org/licenses/LICENSE-2.0) according to the [License Policy](https://www.apache.org/legal/resolved.html)
   - [ ] New dependencies are documented in applicable `LICENSE` and `NOTICE` files
   
   ### Documentation
   
   - [ ] Documentation formatting appears as expected in rendered files
   


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

Posted by "exceptionfactory (via GitHub)" <gi...@apache.org>.
exceptionfactory commented on PR #10836:
URL: https://github.com/apache/nifi/pull/10836#issuecomment-3843434943

   Thanks @dan-s1, moving the existing logging lines as suggested sounds like a good plan, that way it encompasses the totality of the method.


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Repositioned log statements to indicate how long map extensions take. [nifi]

Posted by "exceptionfactory (via GitHub)" <gi...@apache.org>.
exceptionfactory merged PR #10836:
URL: https://github.com/apache/nifi/pull/10836


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

Posted by "mosermw (via GitHub)" <gi...@apache.org>.
mosermw commented on PR #10836:
URL: https://github.com/apache/nifi/pull/10836#issuecomment-3825639144

   Or, as a completely different idea, move the "Expanded 117 NAR files in 4.873 seconds" INFO message farther down in the unpackNars() method, to include the calls to mapExtension()s and populateExtensionMapping() in the timer?


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

Posted by "dan-s1 (via GitHub)" <gi...@apache.org>.
dan-s1 commented on PR #10836:
URL: https://github.com/apache/nifi/pull/10836#issuecomment-3825113757

   This was added per a coworker's frustration as to what what is happening in that gap of time.


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

Posted by "exceptionfactory (via GitHub)" <gi...@apache.org>.
exceptionfactory commented on PR #10836:
URL: https://github.com/apache/nifi/pull/10836#issuecomment-3825291982

   > This was added per a coworker's frustration as to what what is happening in that gap of time.
   
   Thanks @dan-s1. In that case, I'm not sure there is a worthwhile addition.
   
   As mentioned, the existing debug-level logging provides more information if desired. Simply writing more log messages to indicate additional detail is not necessarily the best path forward. If there is a problem with the behavior, that may be worth addressing. The fact that the NAR unpacking described on the Jira issue takes almost 30 seconds is notable, as it seems to indicate either slow decompression or write operations, among some possibilities.


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

Posted by "mosermw (via GitHub)" <gi...@apache.org>.
mosermw commented on PR #10836:
URL: https://github.com/apache/nifi/pull/10836#issuecomment-3825486457

   Adding 2 INFO log messages seems reasonable, if we can identify and describe what NiFi is doing.  We do account for "Expanding NAR files" which took 4.873 seconds in the example below.  What about the 4.052 seconds after that and before the 117 lines of "Loaded NAR file:"?  What is NiFi doing?
   ```
   2026-01-30 19:46:25,215 INFO [main] org.apache.nifi.nar.NarUnpacker Expanding 117 NAR files started
   2026-01-30 19:46:30,088 INFO [main] org.apache.nifi.nar.NarUnpacker Expanded 117 NAR files in 4.873 seconds (4873023800 ns)
   2026-01-30 19:46:34,140 INFO [main] org.apache.nifi.nar.NarClassLoaders Loaded NAR file:
   ```
   
   Maybe we can do one INFO message with "Loading 117 NAR files", change the 117 "Loaded NAR file" messages to the DEBUG level, and finish up with one INFO message "Loaded 117 NAR files in ??? seconds (??? ns)".
   


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] NIFI-15531 Added log statements to indicate how long map extensions take. [nifi]

Posted by "dan-s1 (via GitHub)" <gi...@apache.org>.
dan-s1 commented on PR #10836:
URL: https://github.com/apache/nifi/pull/10836#issuecomment-3843393811

   The debug messages do not really address the issue and really are not necessary. The main concern was the hang time that occurs after the log message on line 205: 
   `logger.info("Expanded {} NAR files in {} seconds ({} ns)", narFiles.size(), durationSeconds, duration);`
   which apparently is caused by how long `mapExtensions` on line 211 takes.
   
   My coworker did suggest perhaps pushing up lines 120-121
   ```
   final long startTime = System.nanoTime();
   logger.info("Expanding {} NAR files started", narFiles.size());
   ```
   above line 119  `if (!narFiles.isEmpty())`
   (since there will always be at the minimum the nar files of the framework)
   and lines 203-205
   ```
   final long duration = System.nanoTime() - startTime;
   final double durationSeconds = TimeUnit.NANOSECONDS.toMillis(duration) / 1000.0;
   logger.info("Expanded {} NAR files in {} seconds ({} ns)", narFiles.size(), durationSeconds, duration);
   ```
   after line 212 `populateExtensionMapping` thereby indicating the hang time is attributed/related to the nar expansions.
   
   Does that make sense?


-- 
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: issues-unsubscribe@nifi.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org