Skip to content
Snippets Groups Projects

Regression: igwn-alert bootstep does not terminate, blocks shutdown of application

    • Closed Issue created by Leo P. Singer @leo-singer

    The igwn-alert bootstep never terminates, which blocks the application from shutting down. The bootstep stop() method must trigger some sentinel that tells the client's run loop to stop.

    Edited by Leo P. Singer
    To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information

    Child items 0

    • No child items are currently assigned. Use child items to break down this issue into smaller parts.

    Activity

    • Leo P. Singer changed milestone to %Review Readiness Presentation

      changed milestone to %Review Readiness Presentation

    • Leo P. Singer added IGWN Alerts label

      added IGWN Alerts label

    • Leo P. Singer assigned to @deep.chatterjee

      assigned to @deep.chatterjee

    • Leo P. Singer changed title from igwn-alert bootstep does not terminate, blocks shutdown of application to Regression: igwn-alert bootstep does not terminate, blocks shutdown of application

      changed title from igwn-alert bootstep does not terminate, blocks shutdown of application to Regression: igwn-alert bootstep does not terminate, blocks shutdown of application

    • Deep Chatterjee created branch 424-regression-igwn-alert-bootstep-does-not-terminate-blocks-shutdown-of-application to address this issue

      created branch 424-regression-igwn-alert-bootstep-does-not-terminate-blocks-shutdown-of-application to address this issue

    • Deep Chatterjee created branch stop-listener-properly to address this issue

      created branch stop-listener-properly to address this issue

    • Deep Chatterjee mentioned in merge request !895 (closed)

      mentioned in merge request !895 (closed)

    • Deep Chatterjee mentioned in merge request !896 (merged)

      mentioned in merge request !896 (merged)

    • Deep Chatterjee closed with merge request !896 (merged)

      closed with merge request !896 (merged)

    • Deep Chatterjee
      Deep Chatterjee @deep.chatterjee ·
      Owner

      Reopening this since this is not completely solved. Using until_eos=True will allow a timeout, but causes an error in autocommit. See: 1ac1d73b

      Example of error:

      [2022-08-25 14:07:50,672: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/threading.py", line 973, in _bootstrap_inner
[2022-08-25 14:07:50,673: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,674: WARNING/MainProcess/IGWNReceiverThread] self.run()
[2022-08-25 14:07:50,675: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 69, in run
[2022-08-25 14:07:50,675: INFO/MainProcess/MainThread] Task gwcelery.tasks.gracedb.create_label[5affd21d-d50a-4a21-adac-e08335f3bf45] received
[2022-08-25 14:07:50,676: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,678: WARNING/MainProcess/IGWNReceiverThread] reraise(*_capture_exception())
[2022-08-25 14:07:50,679: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/_compat.py", line 54, in reraise
[2022-08-25 14:07:50,685: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,686: WARNING/MainProcess/IGWNReceiverThread] raise value
[2022-08-25 14:07:50,686: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67, in run
[2022-08-25 14:07:50,687: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,687: WARNING/MainProcess/IGWNReceiverThread] return old_run_func(self, *a, **kw)
[2022-08-25 14:07:50,688: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/threading.py", line 910, in run
[2022-08-25 14:07:50,689: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,689: WARNING/MainProcess/IGWNReceiverThread] self._target(*self._args, **self._kwargs)
[2022-08-25 14:07:50,689: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/gwcelery/igwn_alert/bootsteps.py", line 55, in listen
[2022-08-25 14:07:50,690: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,691: WARNING/MainProcess/IGWNReceiverThread] for payload, metadata in s.read(
[2022-08-25 14:07:50,691: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/hop/io.py", line 340, in read
[2022-08-25 14:07:50,692: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,692: WARNING/MainProcess/IGWNReceiverThread] for message in self._consumer.stream(autocommit=autocommit, **kwargs):
[2022-08-25 14:07:50,692: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/consumer.py", line 167, in _stream_until_eof
[2022-08-25 14:07:50,693: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 14:07:50,694: WARNING/MainProcess/IGWNReceiverThread] partition_set.remove(m.partition())
[2022-08-25 14:07:50,694: WARNING/MainProcess/IGWNReceiverThread] KeyError
[2022-08-25 14:07:50,694: WARNING/MainProcess/IGWNReceiverThread] :
[2022-08-25 14:07:50,695: WARNING/MainProcess/IGWNReceiverThread] 0
      Edited by Deep Chatterjee
    • Deep Chatterjee reopened

      reopened

      • Cody Messick
        Cody Messick @cody.messick ·
        Owner

        Given that this problem is more involved than we initially thought, should we move this to the O4 milestone? Reminder that the review readiness milestone is due Sep 1 (Thursday).

        The tldr of the situation thus far is that setting until_eos = True not only causes the problem that Deep mentioned above, but also the intended behavior of until_eos = True does not do what we want. Its intended behavior is that it will shut the listener down after the listener processes the current batch of messages, i.e. the listener will turn on, grab whatever is waiting in the kafka queue to be consumed immediately, and then shut down. If we find evidence that setting until_eos = True does not result in this behavior, we should let the hop folks know that there's a bug.

        The underlying problem, as I understand it from talking to @patrick.godwin, is that adc streaming's _stream_forever function (link) never returns anything, meaning that the while self.running line (link) will only ever get evaulated once. Until this is fixed we'll need a workaround.

        Edited by Cody Messick
      • Deep Chatterjee
        Deep Chatterjee @deep.chatterjee ·
        Owner

        I'll make an attempt to fix this one more time, but it will be a workaround, short-term fix. I have started an issue with the hop/adc-streaming team about this: https://github.com/astronomy-commons/adc-streaming/issues/57.

        The bottomline is something like a running attribute, a stop method, should be exposed by the client.

      • Please register or sign in to reply
    • Cody Messick
      Cody Messick @cody.messick ·
      Owner

      Looks like a new error has popped up that I believe is coming from !895 (closed), simply because we didn't see it before that MR.

      [2022-08-25 21:06:35,805: ERROR/MainProcess/IGWNReceiverThread] internal kafka error: KafkaError{code=_TIMED_OUT,val=-185,str="GroupCoordinator: kb-0.prod.hop.scimma.org:9092: 2 request(s) timed out: disconnect (after 23779127ms in state UP)"}
[2022-08-25 21:06:35,867: WARNING/MainProcess/IGWNReceiverThread] Exception in thread
[2022-08-25 21:06:35,868: WARNING/MainProcess/IGWNReceiverThread] IGWNReceiverThread
[2022-08-25 21:06:35,868: WARNING/MainProcess/IGWNReceiverThread] :
[2022-08-25 21:06:35,868: WARNING/MainProcess/IGWNReceiverThread] Traceback (most recent call last):
[2022-08-25 21:06:35,869: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/threading.py", line 973, in _bootstrap_inner
[2022-08-25 21:06:35,870: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,870: WARNING/MainProcess/IGWNReceiverThread] self.run()
[2022-08-25 21:06:35,871: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 69, in run
[2022-08-25 21:06:35,872: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,872: WARNING/MainProcess/IGWNReceiverThread] reraise(*_capture_exception())
[2022-08-25 21:06:35,872: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/_compat.py", line 54, in reraise
[2022-08-25 21:06:35,873: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,873: WARNING/MainProcess/IGWNReceiverThread] raise value
[2022-08-25 21:06:35,874: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67, in run
[2022-08-25 21:06:35,874: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,874: WARNING/MainProcess/IGWNReceiverThread] return old_run_func(self, *a, **kw)
[2022-08-25 21:06:35,875: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/threading.py", line 910, in run
[2022-08-25 21:06:35,877: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,877: WARNING/MainProcess/IGWNReceiverThread] self._target(*self._args, **self._kwargs)
[2022-08-25 21:06:35,878: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/gwcelery/igwn_alert/bootsteps.py", line 54, in listen
[2022-08-25 21:06:35,878: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,878: WARNING/MainProcess/IGWNReceiverThread] for payload, metadata in s.read(
[2022-08-25 21:06:35,879: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/hop/io.py", line 340, in read
[2022-08-25 21:06:35,879: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,880: WARNING/MainProcess/IGWNReceiverThread] for message in self._consumer.stream(autocommit=autocommit, **kwargs):
[2022-08-25 21:06:35,880: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/consumer.py", line 120, in _stream_forever
[2022-08-25 21:06:35,881: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,881: WARNING/MainProcess/IGWNReceiverThread] messages = self._consumer.consume(batch_size, batch_timeout.total_seconds())
[2022-08-25 21:06:35,881: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/errors.py", line 22, in log_client_errors
[2022-08-25 21:06:35,882: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-25 21:06:35,882: WARNING/MainProcess/IGWNReceiverThread] raise(KafkaException.from_kafka_error(kafka_error))
[2022-08-25 21:06:35,882: WARNING/MainProcess/IGWNReceiverThread] adc.errors
[2022-08-25 21:06:35,883: WARNING/MainProcess/IGWNReceiverThread] .
[2022-08-25 21:06:35,883: WARNING/MainProcess/IGWNReceiverThread] KafkaException
[2022-08-25 21:06:35,883: WARNING/MainProcess/IGWNReceiverThread] :
[2022-08-25 21:06:35,884: WARNING/MainProcess/IGWNReceiverThread] Error communicating with Kafka: code=_TIMED_OUT GroupCoordinator: kb-0.prod.hop.scimma.org:9092: 2 request(s) timed out: disconnect (after 23779127ms in state UP)
[2022-08-25 21:06:44,132: ERROR/ForkPoolWorker-889] gwcelery.tasks.detchar.make_omegascan[1c240e19-3712-4f47-8303-2ceacca2673f]: Files do not exist in llhoft_glob
    • Deep Chatterjee mentioned in merge request !905 (merged)

      mentioned in merge request !905 (merged)

    • Cody Messick
      Cody Messick @cody.messick ·
      Owner

      Got another of these messages after reverting all recent changes to the IGWN-Alert bootstep, returning it to its original state before !896 (merged). I'm going to make a new issue since this doesn't seem to be connected to the issue of gracefully shutting down.

      [2022-08-26 14:06:18,352: WARNING/MainProcess/IGWNReceiverThread] Exception in thread
[2022-08-26 14:06:18,354: WARNING/MainProcess/IGWNReceiverThread] IGWNReceiverThread
[2022-08-26 14:06:18,354: WARNING/MainProcess/IGWNReceiverThread] :
[2022-08-26 14:06:18,355: WARNING/MainProcess/IGWNReceiverThread] Traceback (most recent call last):
[2022-08-26 14:06:18,355: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/igwn_alert/client.py", line 226, in listen
[2022-08-26 14:06:18,356: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,357: WARNING/MainProcess/IGWNReceiverThread] for payload, metadata in s.read(
[2022-08-26 14:06:18,357: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/hop/io.py", line 340, in read
[2022-08-26 14:06:18,358: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,358: WARNING/MainProcess/IGWNReceiverThread] for message in self._consumer.stream(autocommit=autocommit, **kwargs):
[2022-08-26 14:06:18,358: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/consumer.py", line 120, in _stream_forever
[2022-08-26 14:06:18,359: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,359: WARNING/MainProcess/IGWNReceiverThread] messages = self._consumer.consume(batch_size, batch_timeout.total_seconds())
[2022-08-26 14:06:18,360: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/errors.py", line 22, in log_client_errors
[2022-08-26 14:06:18,360: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,361: WARNING/MainProcess/IGWNReceiverThread] raise(KafkaException.from_kafka_error(kafka_error))
[2022-08-26 14:06:18,361: WARNING/MainProcess/IGWNReceiverThread] adc.errors
[2022-08-26 14:06:18,361: WARNING/MainProcess/IGWNReceiverThread] .
[2022-08-26 14:06:18,361: WARNING/MainProcess/IGWNReceiverThread] KafkaException
[2022-08-26 14:06:18,362: WARNING/MainProcess/IGWNReceiverThread] :
[2022-08-26 14:06:18,362: WARNING/MainProcess/IGWNReceiverThread] Error communicating with Kafka: code=_TIMED_OUT GroupCoordinator: kb-1.prod.hop.scimma.org:9092: 10 request(s) timed out: disconnect (after 1660526ms in state UP)
[2022-08-26 14:06:18,362: WARNING/MainProcess/IGWNReceiverThread]
During handling of the above exception, another exception occurred:
[2022-08-26 14:06:18,363: WARNING/MainProcess/IGWNReceiverThread] Traceback (most recent call last):
[2022-08-26 14:06:18,363: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/threading.py", line 973, in _bootstrap_inner
[2022-08-26 14:06:18,364: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,364: WARNING/MainProcess/IGWNReceiverThread] self.run()
[2022-08-26 14:06:18,364: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 69, in run
[2022-08-26 14:06:18,365: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,365: WARNING/MainProcess/IGWNReceiverThread] reraise(*_capture_exception())
[2022-08-26 14:06:18,365: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/_compat.py", line 54, in reraise
[2022-08-26 14:06:18,366: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,366: WARNING/MainProcess/IGWNReceiverThread] raise value
[2022-08-26 14:06:18,367: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/sentry_sdk/integrations/threading.py", line 67, in run
[2022-08-26 14:06:18,367: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,367: WARNING/MainProcess/IGWNReceiverThread] return old_run_func(self, *a, **kw)
[2022-08-26 14:06:18,368: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/threading.py", line 910, in run
[2022-08-26 14:06:18,368: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,369: WARNING/MainProcess/IGWNReceiverThread] self._target(*self._args, **self._kwargs)
[2022-08-26 14:06:18,369: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/igwn_alert/client.py", line 243, in listen
[2022-08-26 14:06:18,370: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,370: WARNING/MainProcess/IGWNReceiverThread] callback(topic=metadata.topic.split('.')[1],
[2022-08-26 14:06:18,370: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/hop/io.py", line 396, in __exit__
[2022-08-26 14:06:18,371: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,371: WARNING/MainProcess/IGWNReceiverThread] self.close()
[2022-08-26 14:06:18,372: WARNING/MainProcess/IGWNReceiverThread]   File "/home/emfollow-playground/.local/lib/python3.9/site-packages/hop/io.py", line 374, in close
[2022-08-26 14:06:18,372: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,372: WARNING/MainProcess/IGWNReceiverThread] self._consumer.close()
[2022-08-26 14:06:18,373: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/consumer.py", line 179, in close
[2022-08-26 14:06:18,373: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,374: WARNING/MainProcess/IGWNReceiverThread] self._consumer.close()
[2022-08-26 14:06:18,374: WARNING/MainProcess/IGWNReceiverThread]   File "/cvmfs/oasis.opensciencegrid.org/ligo/sw/conda/envs/igwn-py39-20220317/lib/python3.9/site-packages/adc/errors.py", line 22, in log_client_errors
[2022-08-26 14:06:18,375: WARNING/MainProcess/IGWNReceiverThread]
[2022-08-26 14:06:18,375: WARNING/MainProcess/IGWNReceiverThread] raise(KafkaException.from_kafka_error(kafka_error))
[2022-08-26 14:06:18,375: WARNING/MainProcess/IGWNReceiverThread] adc.errors
[2022-08-26 14:06:18,375: WARNING/MainProcess/IGWNReceiverThread] .
[2022-08-26 14:06:18,376: WARNING/MainProcess/IGWNReceiverThread] KafkaException
[2022-08-26 14:06:18,376: WARNING/MainProcess/IGWNReceiverThread] :
[2022-08-26 14:06:18,376: WARNING/MainProcess/IGWNReceiverThread] Error communicating with Kafka: code=_TIMED_OUT GroupCoordinator: kb-1.prod.hop.scimma.org:9092: 146 request(s) timed out: disconnect (after 60055ms in state UP)
[2022-08-26 14:06:21,126: INFO/ForkPoolWorker-43/MainThread] Task gwcelery.tasks.condor.submit[1d96c7b4-7b0c-411c-a7f6-011d8183bbfb] retry: Retry in 4s: JobRunning({'ExecuteHost': '<10.14.150.10:9618?addrs=10.14.150.10-9618&alias=emfollow-playground.ligo.caltech.edu&noUDP&sock=schedd_2392_4aa0>', 'MyType': 'ExecuteEvent', 'EventTypeNumber': 1, 'Subproc': 0, 'EventTime': '2022-08-26T14:06:14.020', 'Cluster': 23563, 'Proc': 0})
    • Cody Messick mentioned in issue #441 (closed)

      mentioned in issue #441 (closed)

    • Cody Messick
      Cody Messick @cody.messick ·
      Owner

      I'm moving this to the O4 milestone because it's not critical to have solved for the review readiness milestone.

    • Cody Messick changed milestone to %O4

      changed milestone to %O4

    • Deep Chatterjee
      Deep Chatterjee @deep.chatterjee ·
      Owner

      BTW, I wanted to add that the pull request to support graceful termination when running in a thread has been merged (https://github.com/astronomy-commons/adc-streaming/pull/58). We need to wait until there is a new release for adc-streaming. Change to O4 milestone sounds good.

      Edited by Deep Chatterjee
    • Deep Chatterjee closed with merge request !905 (merged)

      closed with merge request !905 (merged)

    Please register or sign in to reply