[BEAM-9399] Ensure that empty messages are not flushed to handler.

[scwhittle]

Fix an issue introduced by
#11096
where empty messages could end up being published to the handler if the PrintStream was flushed when empty. Added a unit test ensuring no empty messages are published.

Thank you for your contribution! Follow this checklist to help us incorporate your contribution quickly and easily:

• Choose reviewer(s) and mention them in a comment (R: @username).
• Format the pull request title like [BEAM-XXX] Fixes bug in ApproximateQuantiles, where you replace BEAM-XXX with the appropriate JIRA issue, if applicable. This will automatically link the pull request to the issue.
• Update CHANGES.md with noteworthy changes.
• If this contribution is large, please file an Apache Individual Contributor License Agreement.

See the Contributor Guide for more tips on how to make review process smoother.

Post-Commit Tests Status (on master branch)

Lang	SDK	Apex	Dataflow	Flink	Gearpump	Samza	Spark
Go		---	---		---	---
Java
Python		---			---	---
XLang	---	---	---		---	---

Pre-Commit Tests Status (on master branch)

---	Java	Python	Go	Website
Non-portable
Portable	---		---	---

See .test-infra/jenkins/README for trigger phrase, status and link of all Jenkins jobs.

[scwhittle]

R: @lukecwik

[lukecwik]

retest this please

[lukecwik]

Run Java PreCommit

[kplanes]

Hi -
I think we have been affected by this issue - do you know which version has the fix, we might have periods where part of the data pushed is empty and it is deadlocking our code - Happy to provide more details if needed. We work with gcp/java/maven+ dataflow runner - Please let me know if this isn't the right space to comment on this bug

[lukecwik]

This was only part of the fix and this change appeared in the 2.21 release. The last part of the fix appears in the 2.25 release.

[kplanes]

Hi @lukecwik - Interestingly enough, I'm having it failing on the 2.23.0 version ?

Code : catch (Exception e) {
System.out.println("Failed to filter user data " + c.element());
e.printStackTrace();

I assume to work around would be to change it from send it to StackTrace to another print out ?

Errror :
java.lang.IllegalStateException: BEAM-9399: publish should not be called with the lock as it may cause deadlock
at org.apache.beam.vendor.guava.v26_0_jre.com.google.common.base.Preconditions.checkState(Preconditions.java:507)
at org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.publishIfNonEmpty(JulHandlerPrintStreamAdapterFactory.java:380)
at org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.println(JulHandlerPrintStreamAdapterFactory.java:332)
at java.lang.Throwable$WrappedPrintStream.println(Throwable.java:748)
at java.lang.Throwable.printStackTrace(Throwable.java:655)
at java.lang.Throwable.printStackTrace(Throwable.java:643)
at java.lang.Throwable.printStackTrace(Throwable.java:634)
at com.metix.historic.transforms.FilterAndMapPatientsByAge.processElement(FilterAndMapPatientsByAge.java:25)

[lukecwik]

That would work.

Hi @lukecwik - Interestingly enough, I'm having it failing on the 2.23.0 version ?

Code : catch (Exception e) {
System.out.println("Failed to filter user data " + c.element());
e.printStackTrace();

I assume to work around would be to change it from send it to StackTrace to another print out ?

Errror :
java.lang.IllegalStateException: BEAM-9399: publish should not be called with the lock as it may cause deadlock
at org.apache.beam.vendor.guava.v26_0_jre.com.google.common.base.Preconditions.checkState(Preconditions.java:507)
at org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.publishIfNonEmpty(JulHandlerPrintStreamAdapterFactory.java:380)
at org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.println(JulHandlerPrintStreamAdapterFactory.java:332)
at java.lang.Throwable$WrappedPrintStream.println(Throwable.java:748)
at java.lang.Throwable.printStackTrace(Throwable.java:655)
at java.lang.Throwable.printStackTrace(Throwable.java:643)
at java.lang.Throwable.printStackTrace(Throwable.java:634)
at com.metix.historic.transforms.FilterAndMapPatientsByAge.processElement(FilterAndMapPatientsByAge.java:25)

Yes, using another printstream would work around the issue.

@scwhittle Any ideas as to why it would be broken in 2.23?

[scwhittle]

On Wed, Oct 14, 2020, 7:06 PM Lukasz Cwik ***@***.***> wrote: That would work. Hi @lukecwik <https://github.com/lukecwik> - Interestingly enough, I'm having it failing on the 2.23.0 version ? Code : catch (Exception e) { System.out.println("Failed to filter user data " + c.element()); e.printStackTrace(); I assume to work around would be to change it from send it to StackTrace to another print out ? Errror : java.lang.IllegalStateException: BEAM-9399 <https://issues.apache.org/jira/browse/BEAM-9399>: publish should not be called with the lock as it may cause deadlock at org.apache.beam.vendor.guava.v26_0_jre.com.google.common.base.Preconditions.checkState(Preconditions.java:507) at org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.publishIfNonEmpty(JulHandlerPrintStreamAdapterFactory.java:380) at org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.println(JulHandlerPrintStreamAdapterFactory.java:332) at java.lang.Throwable$WrappedPrintStream.println(Throwable.java:748) at java.lang.Throwable.printStackTrace(Throwable.java:655) at java.lang.Throwable.printStackTrace(Throwable.java:643) at java.lang.Throwable.printStackTrace(Throwable.java:634) at com.metix.historic.transforms.FilterAndMapPatientsByAge.processElement(FilterAndMapPatientsByAge.java:25) Yes, using another printstream would work around the issue.

Could also avoid e.printStackTrace() and instead print the stack trace to a string and then print, for example using https://guava.dev/releases/23.0/api/docs/com/google/common/base/Throwables.html#getStackTraceAsString-java.lang.Throwable- System.out.println("Failed to filter user data " + c.element() + " " + Throwables.getStackTraceAsString(e));

@scwhittle <https://github.com/scwhittle> Any ideas as to why it would be broken in 2.23?

It is broken because #11096 changed a potential deadlock into consistent IllegalStateException. This was unintended, I didn't consider that other things might synchronize on the overridden System.err PrintStream. Throwable.printStackTrace does this. This was fixed by #12825 which was cherrypicked to the 2.25 release. The commit comment there has more details.

…

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#11351 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABBZZTC4FDINTANLXPZTNUDSKXLCLANCNFSM4MEFYJFQ> .

[wclaralee]

Hello, I am now getting this error since adding usage of BigQuery Storage API when reading from a table using .withMethod(Method.DIRECT_READ) using beam 2.21.0. The error stack trace I get is similar to the one above:
Error message from worker: java.lang.IllegalStateException: BEAM-9399: publish should not be called with the lock as it may cause deadlock org.apache.beam.vendor.guava.v26_0_jre.com.google.common.base.Preconditions.checkState(Preconditions.java:507) org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.publishIfNonEmpty(JulHandlerPrintStreamAdapterFactory.java:380) org.apache.beam.runners.dataflow.worker.logging.JulHandlerPrintStreamAdapterFactory$JulHandlerPrintStream.println(JulHandlerPrintStreamAdapterFactory.java:332) java.lang.Throwable$WrappedPrintStream.println(Throwable.java:748) java.lang.Throwable.printStackTrace(Throwable.java:655) java.lang.Throwable.printStackTrace(Throwable.java:643) java.lang.Throwable.printStackTrace(Throwable.java:634) org.slf4j.helpers.Util.report(Util.java:124)
(^truncated a bit.)
Please let me know. Thank you.