Small hprof file causes error on load

[karianna]

This file loads normally in other tooling (Eclipse MAT directly for example). However in Jifa:

[Begin task] Parsing 1639565894350-censum.hprof [Begin task] Parsing /Users/karianna/jifa_workspace/heap-dump/1639565894350-censum.hprof/1639565894350-censum.hprof [Sub task] Scanning /Users/karianna/jifa_workspace/heap-dump/1639565894350-censum.hprof/1639565894350-censum.hprof org.eclipse.jifa.common.JifaException: org.eclipse.jifa.hda.api.AnalysisException: org.eclipse.mat.SnapshotException: The HPROF parser encountered a violation of the HPROF specification that it could not safely handle. This could be due to file truncation or a bug in the JVM. Please consider filing a bug at eclipse.org. To continue parsing the dump anyway, you can use -DhprofStrictnessWarning=true or set the strictness mode under Preferences > HPROF Parser > Parser Strictness. See the inner exception for details. at org.eclipse.jifa.worker.support.Analyzer.getOrBuild(Analyzer.java:78) at org.eclipse.jifa.worker.support.Analyzer.getOrBuildHeapDumpAnalyzer(Analyzer.java:87) at org.eclipse.jifa.worker.support.Analyzer.analyze(Analyzer.java:123) at org.eclipse.jifa.worker.route.AnalysisRoute.analyze(AnalysisRoute.java:50) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.eclipse.jifa.worker.route.RouteFiller.lambda$registerMethodRoute$0(RouteFiller.java:130) at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48) at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:160) at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:96) at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:158) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: org.eclipse.jifa.hda.api.AnalysisException: org.eclipse.mat.SnapshotException: The HPROF parser encountered a violation of the HPROF specification that it could not safely handle. This could be due to file truncation or a bug in the JVM. Please consider filing a bug at eclipse.org. To continue parsing the dump anyway, you can use -DhprofStrictnessWarning=true or set the strictness mode under Preferences > HPROF Parser > Parser Strictness. See the inner exception for details. at org.eclipse.jifa.hda.impl.HeapDumpAnalyzerImpl.$(HeapDumpAnalyzerImpl.java:165) at org.eclipse.jifa.hda.impl.HeapDumpAnalyzerImpl$ProviderImpl.provide(HeapDumpAnalyzerImpl.java:1848) at org.eclipse.jifa.hdp.provider.MATProvider.provide(MATProvider.java:44) at org.eclipse.jifa.worker.support.Analyzer.lambda$getOrBuildHeapDumpAnalyzer$0(Analyzer.java:88) at org.eclipse.jifa.worker.support.Analyzer.getOrBuild(Analyzer.java:76) ... 16 more Caused by: org.eclipse.mat.SnapshotException: The HPROF parser encountered a violation of the HPROF specification that it could not safely handle. This could be due to file truncation or a bug in the JVM. Please consider filing a bug at eclipse.org. To continue parsing the dump anyway, you can use -DhprofStrictnessWarning=true or set the strictness mode under Preferences > HPROF Parser > Parser Strictness. See the inner exception for details. at org.eclipse.mat.hprof.Pass1Parser.read(Pass1Parser.java:168) at org.eclipse.mat.hprof.HprofIndexBuilder.fill(HprofIndexBuilder.java:84) at org.eclipse.mat.parser.internal.SnapshotFactoryImpl.parse(SnapshotFactoryImpl.java:331) at org.eclipse.mat.parser.internal.SnapshotFactoryImpl.openSnapshot(SnapshotFactoryImpl.java:202) at org.eclipse.mat.snapshot.SnapshotFactory.openSnapshot(SnapshotFactory.java:149) at org.eclipse.jifa.hda.impl.HeapDumpAnalyzerImpl$ProviderImpl.lambda$provide$0(HeapDumpAnalyzerImpl.java:1848) at org.eclipse.jifa.hda.impl.HeapDumpAnalyzerImpl.$(HeapDumpAnalyzerImpl.java:163) ... 20 more Caused by: org.eclipse.mat.SnapshotException: (Possibly) Invalid HPROF file: Expected to read another 198,948,580 bytes, but only 187,389,383 bytes are available for heap dump record 0x1c at 0x555a30. at org.eclipse.mat.hprof.Pass1Parser.read(Pass1Parser.java:169) ... 26 more

[D-D-H]

Hi @karianna , Thanks for reporting this.

Jifa currently uses MAT as the hprof parser, and the current version is 1.12.0. From the log, the exception is caused by the invalid HPROF file format. I'm not sure why your MAT works, I guess it might be because your MAT enables hprofStrictnessWarning.

If it is convenient for you, can you upload this hprof?

[karianna]

I'm not able to load hprof files to GitHub, is there another location I could share to?

[D-D-H]

Could you join our slack channel: https://eclipsejifa.slack.com/ I think you can upload the file there :-)

[karianna]

I think I need an invite to there? Slack's not letting me join... I'm martijnverburg AT gmail DOT com

[karianna]

This only fails when running the full docker-copmse mysql, backend master and backend worker. If you only run the backend work and the front end, this works fine.

[D-D-H]

This only fails when running the full docker-copmse mysql, backend master and backend worker. If you only run the backend work and the front end, this works fine.

I took a preliminary look. It seems that the problem is caused by the order of command execution. I will prepare a more stable demo.

[D-D-H]

I rewrite the demo, please try it when you have time, looking forward to your feedback.

[karianna]

Almost there I think: The database still didn't like the connection:

master_1    | 2021-12-20 14:54:36.168 [vert.x-worker-thread-0] [INFO] Create service proxy done
master_1    | 2021-12-20 14:54:36.234 [vertx-jdbc-service-get-connection-thread] [INFO] {dataSource-1} inited
master_1    | 2021-12-20 14:54:36.296 [Druid-ConnectionPool-Create-2147286282] [ERROR] create connection SQLException, url: jdbc:mysql://database:3306/jifa?useUnicode=true&characterEncoding=utf8&enabledTLSProtocols=TLSv1.2, errorCode 0, state 08S01
master_1    | com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
master_1    |
master_1    | The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
master_1    | 	at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:835) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:455) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:240) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:199) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1652) ~[druid-1.2.3.jar:1.2.3]
master_1    | 	at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1718) ~[druid-1.2.3.jar:1.2.3]
master_1    | 	at com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:2785) [druid-1.2.3.jar:1.2.3]
master_1    | Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure
master_1    |
master_1    | The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
master_1    | 	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?]
master_1    | 	at jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:?]
master_1    | 	at jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:?]
master_1    | 	at java.lang.reflect.Constructor.newInstance(Constructor.java:490) ~[?:?]
master_1    | 	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.protocol.a.NativeSocketConnection.connect(NativeSocketConnection.java:91) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.NativeSession.connect(NativeSession.java:152) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:955) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:825) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	... 6 more
master_1    | Caused by: java.net.ConnectException: Connection refused (Connection refused)
master_1    | 	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:?]
master_1    | 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399) ~[?:?]
master_1    | 	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242) ~[?:?]
master_1    | 	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224) ~[?:?]
master_1    | 	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:?]
master_1    | 	at java.net.Socket.connect(Socket.java:609) ~[?:?]
master_1    | 	at com.mysql.cj.protocol.StandardSocketFactory.connect(StandardSocketFactory.java:155) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.protocol.a.NativeSocketConnection.connect(NativeSocketConnection.java:65) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.NativeSession.connect(NativeSession.java:152) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:955) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:825) ~[mysql-connector-java-8.0.15.jar:8.0.15]
master_1    | 	... 6 more

Not sure since the TLS parameter is now passed

[D-D-H]

This problem cannot be reproduced in my local environment, I will try to verify in other environments. Sorry about this.

[y1yang0]

master_1 | Caused by: java.net.ConnectException: Connection refused (Connection refused)

Can you manually connect to the database without using Jifa?

[D-D-H]

I added a heath check for database so that master will not be startup until database is ready.

[karianna]

That's getting much closer now, two more things I think:

1. There's a typo in the healthcheck 10S should be 10s
2. I'm no longer getting the cannot connect exceptions, but the output log still has:

021-12-21T11:06:31.330787Z 81 [Note] Access denied for user 'root'@'localhost' (using password: NO)

This does appear to lead to the failure of not being able to upload a file.

3. Probably worth adding the frontend URL (http://127.0.0.1:8089) to the README.md file so folks know where to log into once it starts. Note browsers/plugins like to try to change http to https, also worth warning the user about that (or adding a self signed cert)

[D-D-H]

That's getting much closer now, two more things I think:

1. There's a typo in the healthcheck 10S should be 10s
2. I'm no longer getting the cannot connect exceptions, but the output log still has:

021-12-21T11:06:31.330787Z 81 [Note] Access denied for user 'root'@'localhost' (using password: NO)

I think it's caused by the health check, and I fixed it.

This does appear to lead to the failure of not being able to upload a file.

Currently, the master mode does not support upload, although our internal version supports it (bridging through OSS), I will fix this problem as soon as possible.

3. Probably worth adding the frontend URL (http://127.0.0.1:8089) to the README.md file so folks know where to log into once it starts. Note browsers/plugins like to try to change http to https, also worth warning the user about that (or adding a self signed cert)

Good idea, updated.

[D-D-H]

I filed an issue to fix upload problem in master & worker mode.