Open
Description
Recently, I observed that one of the MRelative related integration tests is failing (i.e. magnitude/MRelative/single-detector-multi-stream-0001) with the following log output:
22: Running integration test with CLI args: scdetect-cc --config-file=/tmp/scdetect/378c-06a0-f7a5-4a47/scdetect-cc.cfg --debug --offline --playback --templates-reload --ep=/tmp/scdetect/378c-06a0-f7a5-4a47/ep.scml --agencyID=TEST --templates-json=/home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/templates.json --inventory-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/inventory.scml --event-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/catalog.scml --record-url=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed --record-starttime=2019-11-05T05:10:00 --config-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/config.scml
22: [context:
22: sample = --templates-json=/home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/templates.json --inventory-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/inventory.scml --event-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/catalog.scml --record-url=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed --record-starttime=2019-11-05T05:10:00 --config-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/config.scml; ]
22: Path to temporary test data: "/tmp/scdetect/378c-06a0-f7a5-4a47"
22: [context:
22: sample = --templates-json=/home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/templates.json --inventory-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/inventory.scml --event-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/catalog.scml --record-url=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed --record-starttime=2019-11-05T05:10:00 --config-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/config.scml; ]
22: 08:21:26 [debug] Adding plugin path: .
22: 08:21:26 [debug] Adding plugin path: /home/runner/.seiscomp/plugins
22: 08:21:26 [debug] Adding plugin path: /home/runner/seiscomp/lib/plugins
22: 08:21:26 [debug] Adding plugin path: /home/runner/seiscomp/lib
22: 08:21:26 [debug] Adding plugin path: /home/runner/seiscomp/share/plugins
22: 08:21:26 [debug] Adding plugin path: /home/runner/seiscomp/share/plugins/scdetect-cc
22: 08:21:26 [info] No plugins loaded
22: 08:21:26 [info] Loading complete inventory from file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/inventory.scml
22: 08:21:26 [info] Finished loading complete inventory
22: 08:21:26 [info] Loading configuration module file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/config.scml
22: 08:21:26 [debug] another object with publicID 'Config' exists already
22: 08:21:26 [info] Finished loading configuration module
22: 08:21:26 [debug] trying to open stream file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed
22: 08:21:26 [info] Playback mode enabled
22: 08:21:26 [info] Loading events from file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/catalog.scml
22: 08:21:26 [debug] Found database version v0.12
22: 08:21:26 [debug] Found database version v0.12
22: 08:21:26 [info] Finished loading events
22: 08:21:26 [info] Loading template configuration from /home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/templates.json
22: 08:21:26 [debug] Creating detector processor (id=detector-01) ...
22: 08:21:26 [debug] [8D.RAW2..HHE (8D.RAW2..HHE)] using arrival pick: origin=smi:ch.ethz.sed/sc3a/origin/NLL.20191105125505.255283.1897990, time=2019-11-05T04:23:50.083441Z, phase=Sg, stream=8D.RAW2..HHT
22: 08:21:26 [debug] [8D.RAW2..HHE (8D.RAW2..HHE)] loaded stream from inventory for epoch: start=2019-11-05T04:23:49.583442Z, end=2019-11-05T04:23:52.083441Z
22: 08:21:26 [debug] [8D.RAW2..HHE (8D.RAW2..HHE)] creating template waveform processor with id: detector-01::template-03
22: 08:21:26 [debug] trying to open stream file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed
22: 08:21:27 [debug] [detector-01::template-03] [8D.RAW2..HHE (8D.RAW2..HHE)] filters configured: filter=""
22: 08:21:27 [debug] [8D.RAW2..HHN (8D.RAW2..HHN)] using arrival pick: origin=smi:ch.ethz.sed/sc3a/origin/NLL.20191105125505.255283.1897990, time=2019-11-05T04:23:50.083441Z, phase=Sg, stream=8D.RAW2..HHT
22: 08:21:27 [debug] [8D.RAW2..HHN (8D.RAW2..HHN)] loaded stream from inventory for epoch: start=2019-11-05T04:23:49.583442Z, end=2019-11-05T04:23:52.083441Z
22: 08:21:27 [debug] [8D.RAW2..HHN (8D.RAW2..HHN)] creating template waveform processor with id: detector-01::template-02
22: 08:21:27 [debug] trying to open stream file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed
22: 08:21:27 [debug] [detector-01::template-02] [8D.RAW2..HHN (8D.RAW2..HHN)] filters configured: filter=""
22: 08:21:27 [debug] [8D.RAW2..HHZ (8D.RAW2..HHZ)] using arrival pick: origin=smi:ch.ethz.sed/sc3a/origin/NLL.20191105125505.255283.1897990, time=2019-11-05T04:23:49.099929Z, phase=Pg, stream=8D.RAW2..HHZ
22: 08:21:27 [debug] [8D.RAW2..HHZ (8D.RAW2..HHZ)] loaded stream from inventory for epoch: start=2019-11-05T04:23:48.59993Z, end=2019-11-05T04:23:51.099929Z
22: 08:21:27 [debug] [8D.RAW2..HHZ (8D.RAW2..HHZ)] creating template waveform processor with id: detector-01::template-01
22: 08:21:27 [debug] trying to open stream file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed
22: 08:21:27 [debug] [detector-01::template-01] [8D.RAW2..HHZ (8D.RAW2..HHZ)] filters configured: filter=""
22: 08:21:27 [debug] Loading binding configuration
22: 08:21:27 [debug] Application initialized
22: 08:21:27 [debug] Subscribing to streams required for processing
22: 08:21:27 [debug] Subscribing to stream: 8D.RAW2..HHE
22: 08:21:27 [debug] Subscribing to stream: 8D.RAW2..HHN
22: 08:21:27 [debug] Subscribing to stream: 8D.RAW2..HHZ
22: 08:21:27 [info] Starting record acquisition
22: 08:21:27 [debug] [detector-01::template-03] Initialize stream: sampling_frequency=200.000000
22: 08:21:27 [debug] [detector-01::template-02] Initialize stream: sampling_frequency=200.000000
22: 08:21:27 [debug] [detector-01::template-01] Initialize stream: sampling_frequency=200.000000
22: 08:21:29 [debug] [detector-01] Detector result score=1.000000, associated_results=3
22: 08:21:29 [debug] [detector-01] Start processing detection (time=2019-11-05T05:23:47.640489Z, associated_results=3) ...
22: 08:21:29 [debug] [8D.RAW2..HHE] Added detection: id="Origin/20220718082129.581455.51186"
22: 08:21:29 [debug] Current detection count: 1
22: 08:21:29 [debug] [8D.RAW2..HHN] Added detection: id="Origin/20220718082129.581455.51186"
22: 08:21:29 [debug] Current detection count: 2
22: 08:21:29 [debug] [8D.RAW2..HHZ] Added detection: id="Origin/20220718082129.581455.51186"
22: 08:21:29 [debug] Current detection count: 3
22: 08:21:29 [debug] [detector-01::5f7b312b-097f-4a97-8eff-51787b275f78::18d4ab1d-a17a-41a3-baf8-599b21003ce1] [8D.RAW2..HH] Configured amplitude processor without filter: filter=""
22: 08:21:29 [debug] [detector-01::5f7b312b-097f-4a97-8eff-51787b275f78::46437b87-870a-4e5d-a8a5-399d780d5c50] [8D.RAW2..HH] Configured amplitude processor without filter: filter=""
22: 08:21:29 [debug] [detector-01::5f7b312b-097f-4a97-8eff-51787b275f78::45adc5da-6c03-429e-8343-e44c8a2118ca] [8D.RAW2..HH] Configured amplitude processor without filter: filter=""
22: 08:21:29 [debug] [8D.RAW2..HHE] Added time window processor: id=detector-01::5f7b312b-097f-4a97-8eff-51787b275f78
22: 08:21:29 [debug] Current time window processor count: 1
22: 08:21:29 [debug] [8D.RAW2..HHN] Added time window processor: id=detector-01::5f7b312b-097f-4a97-8eff-51787b275f78
22: 08:21:29 [debug] Current time window processor count: 2
22: 08:21:29 [debug] [8D.RAW2..HHZ] Added time window processor: id=detector-01::5f7b312b-097f-4a97-8eff-51787b275f78
22: 08:21:29 [debug] Current time window processor count: 3
22: 08:21:29 [debug] [detector-01::5f7b312b-097f-4a97-8eff-51787b275f78] Creating amplitude (value=1.000000, starttime=2019-11-05T05:23:48.595001Z, endtime=2019-11-05T05:23:51.100001Z) ...
22: 08:21:29 [debug] [detector-01::f07363ea-df18-4b04-acba-75b0ee56432a] Created station magnitude for origin (Origin/20220718082129.581455.51186): public_id=StationMagnitude/20220718082129.588989.51191, type=MRelative
22: 08:21:29 [debug] [8D.RAW2..HHE] Removing time window processor: id=detector-01::5f7b312b-097f-4a97-8eff-51787b275f78, status=100, status_value=100.000000
22: 08:21:29 [debug] Current time window processor count: 2
22: 08:21:29 [debug] [8D.RAW2..HHN] Removing time window processor: id=detector-01::5f7b312b-097f-4a97-8eff-51787b275f78, status=100, status_value=100.000000
22: 08:21:29 [debug] Current time window processor count: 1
22: 08:21:29 [debug] [8D.RAW2..HHZ] Removing time window processor: id=detector-01::5f7b312b-097f-4a97-8eff-51787b275f78, status=100, status_value=100.000000
22: 08:21:29 [debug] Current time window processor count: 0
22: 08:21:29 [debug] [8D.RAW2..HHE] Removed detection: id="Origin/20220718082129.581455.51186"
22: 08:21:29 [debug] Current detection count: 2
22: 08:21:29 [debug] [8D.RAW2..HHN] Removed detection: id="Origin/20220718082129.581455.51186"
22: 08:21:29 [debug] Current detection count: 1
22: 08:21:29 [debug] [8D.RAW2..HHZ] Removed detection: id="Origin/20220718082129.581455.51186"
22: 08:21:29 [debug] Current detection count: 0
22: 08:21:31 [info] Finished acquisition
22: 08:21:31 [info] Sending close event after finishing acquisition
22: 08:21:31 [info] Close event received, returning
22: 08:21:31 [debug] [detector-01] Terminating ...
22: 08:21:31 [debug] Found 1 origins.
22: 08:21:31 [debug] Leaving ::done
22: 08:21:31 [info] Waiting for record thread
22: ../../../../../../../../seiscomp/src/extras/scdetect/src/apps/cc/test/integration_utils.cpp(620): error: in "cc_integration/_30": check equalOptional(lhs, rhs, [](DataModel::AmplitudeCPtr amp) { return amp->timeWindow(); }) has failed
22: Failure occurred in a following context:
22: sample = --templates-json=/home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/templates.json --inventory-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/inventory.scml --event-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/catalog.scml --record-url=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/data.mseed --record-starttime=2019-11-05T05:10:00 --config-db=file:///home/runner/work/scdetect/scdetect/seiscomp/src/extras/scdetect/src/apps/cc/test/data/integration/magnitude/MRelative/single-detector-multi-stream-0001/config.scml;
The behavior doesn't seem to be reproducable, since after rerunning the test, CI passes successfully (see e.g. https://github.com/swiss-seismological-service/scdetect/actions/runs/2689087143). Also, I never observed a similar behavior when executing tests locally.
Activity