[YANGTOOLS-1094] Taking more than 10mins when parsing YANG models Created: 07/Apr/20  Updated: 08/Apr/20  Resolved: 08/Apr/20

Status: Resolved
Project: yangtools
Component/s: parser
Affects Version/s: 3.0.5, 2.1.18
Fix Version/s: None

Type: Bug Priority: High
Reporter: Clark Lin Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Runtime environment information:
JVM Version:Java HotSpot(TM) 64-Bit Server VM (25.121-b13) for linux-amd64 JRE (1.8.0_121-b13)
Numbers of core of CPU:8
Total physical memory size:63.05G
OS version:uname:Linux 3.0.101-94-default #1 SMP Thu Jan 26 12:20:59 UTC 2017 (c499ea8) x86_64


Attachments: PNG File yangparser.png    

 Description   

Hi,

Recently, we have a time consuming issue when parsing 120+ YANG models with ODL yang tools version 3.0.5, it takes more than 10 mins.

Let me try to describe the steps reproducing this issue.
1.Download all YANG models from server, and writing them to files.
2.Feed all YANG models files to ODL, we called the following API.

parseSources(StatementParserMode.DEFAULT_MODE, null,files.stream().map(YangTextSchemaSource::forFile).collect(Collectors.toList()))
private SchemaContext parseSources(final StatementParserMode parserMode, final Set<QName> supportedFeatures,
 final Collection<? extends SchemaSourceRepresentation> sources) throws YangParserException, IOException {
 YangParserFactory factory = new YangParserFactoryImpl();
 final YangParser parser = factory.createParser(parserMode);
 if (supportedFeatures != null) {
 parser.setSupportedFeatures(supportedFeatures);
 }
 parser.addSources(sources);
 return parser.buildSchemaContext();
 }

I checked the ODL source code in deeper, main code snippet as below:

for (final ModelProcessingPhase phase : PHASE_EXECUTION_ORDER) {
 startPhase(phase);
 loadPhaseStatements();
 completePhaseActions();
 endPhase(phase);
 }

Main problems happened in last phase ModelProcessingPhase.EFFECTIVE_MODEL marked by red , I tried to extract main logs and see the last phase takes more than 10 mins.

2020-03-19T08:05:54,275 DEBUG  Global phase SOURCE_PRE_LINKAGE started

2020-03-19T08:06:14,994 DEBUG  Global phase SOURCE_PRE_LINKAGE finished

2020-03-19T08:06:16,691 DEBUG  Global phase SOURCE_LINKAGE started

2020-03-19T08:06:39,595 DEBUG  Global phase SOURCE_LINKAGE finished

2020-03-19T08:06:41,549 DEBUG  Global phase STATEMENT_DEFINITION started

2020-03-19T08:06:45,642 DEBUG  Global phase STATEMENT_DEFINITION finished

2020-03-19T08:06:47,325 DEBUG  Global phase FULL_DECLARATION started

2020-03-19T08:08:42,069 DEBUG  Global phase FULL_DECLARATION finished

 

2020-03-19T08:08:43,726 DEBUG  Global phase EFFECTIVE_MODEL started

2020-03-19T08:19:34,745 DEBUG  Global phase EFFECTIVE_MODEL finished

 

Meanwhile, I also run unit test for YANG parser method at the same environment, it is weird that unit test running is quite fast.

 

Also,stack trace tree of runtime is attached for your reference.

We are blocked by this issue for a long time,could you please help look into it with high priority?

Thanks



 Comments   
Comment by Clark Lin [ 08/Apr/20 ]

Hi,

 

This is due to huge parse models logs needs to be written to disk, which called synchronized methods and then takes much more time, so we decided to turn off parse logs, then this issue goes away.

Generated at Wed Feb 07 20:55:10 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.