Virtual Timeslots: Remove workarounds and replace with Steering's native approach

changed milestone to %1.0-alpha5 — Capable Capybara

added P2 label

assigned to @david

marked this issue as related to aura#176 (closed)

changed title from Virtual Timeslots: Remove workarounds and replace with Steering's native appraoch to Virtual Timeslots: Remove workarounds and replace with Steering's native approach

unassigned @david

assigned to @eigenwijsje

unassigned @eigenwijsje

added size:s label

changed the description

marked this issue as related to #135 (closed)

added time estimate of 5h

assigned to @chrizz

added To Do label

added Cycle [3/24] label

added Doing label and removed To Do label

mentioned in issue steering#154 (closed)

added Cycle [4/24] label

Changed implementation as described above but doesn't work yet due to mismatching type schemes.

Can you please elaborate what you mean? Of course implementation has to be adapted to the schema changes.

Also, as long the implementation of steering#154 (closed) and steering#120 (closed) is not finished, this task cannot be done.

/playout returns different datatypes for virtual / non-virtual timeslots
I expected to get all timeslots by setting includeVirtual to true; instead I need to do 2 queries each for virtual and regular timeslots

This does not simplify the current implementation and needs even more special handling.

/playout returns different datatypes for virtual / non-virtual timeslots

Yes, as replied in multiple comments - this is wrong. there should be only one type.

I expected to get all timeslots by setting includeVirtual to true; instead I need to do 2 queries each for virtual and regular timeslots

Jup, as you expected all timeslots should be returned within one query.

edit: to me it looks like it's working on the API side. Normal and virtual timeslots are returned at the same time:

I expected to adapt the implementation anyway but just need some clarfication.

Included the latest changes of the steering swagger api models and added a test case for deserializing the returned data.

I tried to fix the mismatch between the model and the actual data by setting PlayoutProgramEntry.timeslot nullable and/or removing the field from the required array; but without success yet.

Deserialization succeeds if includeVirtual is false (querying non-null TimeSlots only) and fails if virtual timeslots are included:

Traceback (most recent call last):
  File "./test_scheduling_api_steering.py", line 86, in test_api_steering_current_timeslot_model
    t = PlayoutProgramEntry.from_dict(obj)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "./aura_steering_api/models/playout_program_entry.py", line 113, in from_dict
    timeslot = TimeSlot.from_dict(_timeslot)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "./aura_steering_api/models/time_slot.py", line 75, in from_dict
    d = src_dict.copy()
        ^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'copy'

@kmohrf @eigenwijsje do you have any idea what in the JSON schema is causing this?

Without looking at the test code (or the generate client code), only by looking at the serializer and the way the OpenAPI schema renders it, I would guess the allow_null=True parameter is missing in the TimeslotSerializer.

I’m adding it now and when the pipeline finishes building a new image, and you re-run your tests, we will see if it works.

mentioned in issue steering#120 (closed)

added 20h of time spent

I adapted the latest steering api model changes.

engine needs unique identifiers for the same objects but the returned IDs change with every request:

        TIME:1722197780.273948 - local:ID#2024-07-28T20:16:20.273948+00:00...2024-07-28T21:00:00+00:00: 22:16:20 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197811.421999 - local:ID#2024-07-28T20:16:51.421999+00:00...2024-07-28T21:00:00+00:00: 22:16:51 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197842.576872 - local:ID#2024-07-28T20:17:22.576872+00:00...2024-07-28T21:00:00+00:00: 22:17:22 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197873.727652 - local:ID#2024-07-28T20:17:53.727652+00:00...2024-07-28T21:00:00+00:00: 22:17:53 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197904.88006 - local:ID#2024-07-28T20:18:24.880060+00:00...2024-07-28T21:00:00+00:00: 22:18:24 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197936.214493 - local:ID#2024-07-28T20:18:56.214493+00:00...2024-07-28T21:00:00+00:00: 22:18:56 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197967.366991 - local:ID#2024-07-28T20:19:27.366991+00:00...2024-07-28T21:00:00+00:00: 22:19:27 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722197998.517804 - local:ID#2024-07-28T20:19:58.517804+00:00...2024-07-28T21:00:00+00:00: 22:19:58 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198029.672346 - local:ID#2024-07-28T20:20:29.672346+00:00...2024-07-28T21:00:00+00:00: 22:20:29 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198060.828293 - local:ID#2024-07-28T20:21:00.828293+00:00...2024-07-28T21:00:00+00:00: 22:21:00 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198091.97684 - local:ID#2024-07-28T20:21:31.976840+00:00...2024-07-28T21:00:00+00:00: 22:21:31 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198123.137047 - local:ID#2024-07-28T20:22:03.137047+00:00...2024-07-28T21:00:00+00:00: 22:22:03 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198154.377323 - local:ID#2024-07-28T20:22:34.377323+00:00...2024-07-28T21:00:00+00:00: 22:22:34 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198185.526359 - local:ID#2024-07-28T20:23:05.526359+00:00...2024-07-28T21:00:00+00:00: 22:23:05 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198216.674357 - local:ID#2024-07-28T20:23:36.674357+00:00...2024-07-28T21:00:00+00:00: 22:23:36 - 23:00:00 [Show#256: Musikprogramm] | remote: None                      ↦ (add | currently playing)
        TIME:1722198247.827176 - local:None                      | remote: ID#2024-07-28T20:24:07.827176+00:00...2024-07-28T21:00:00+00:00: 22:24:07 - 23:00:00 [Show#256: Musikprogramm] ↦ (add)

added Blocked label and removed Doing label

added 10h of time spent

unassigned @chrizz

changed milestone to %1.0-alpha6 — Wondrous Whale

changed milestone to %1.0-alpha5 — Capable Capybara

changed milestone to %1.0-alpha6 — Wondrous Whale

changed milestone to %1.0-alpha5 — Capable Capybara

mentioned in merge request !46 (merged)

assigned to @david

added Doing label and removed Blocked label

assigned to @Loxbie and unassigned @david

removed Doing label

closed

mentioned in issue aura#359 (closed)

reopened

I am reopening this ticket due to a possible unresolved issue with virtual timeslots. See aura#359 (closed) for testing context.

The engine successfully pushes a song to the queue, and it is correctly received by engine-core. However, the engine skips the actual playback or the start of the timeslot. The exact cause is unclear, but I suspect the engine might be assuming that it can skip the timeslot.

2024-10-16 11:34:44,926:engine:INFO - ^[[36m=== preload_group('PlaylistItem [11:35:00 - 11:39:15 | 255.31sec | Source: ...file://3/6]') ===^[[0m - [scheduler.py:176-do_preload()]
2024-10-16 11:34:44,927:engine:INFO - ^[[35mGot free 'fs' channel 'in_queue_1'^[[0m - [mixer.py:160-get_free_channel()]
2024-10-16 11:34:44,927:engine:INFO - ^[[35min_queue_1.push('/var/audio/source/3/6.flac')^[[0m - [channels.py:347-load()]
2024-10-16 11:34:59,925:engine:INFO - ^[[36m=== on_timeslot_start('ID#7683b173-1c7e-4a81-814f-7511855688de: 11:35:00 - 11:40:00 [Show#3: Test]') ===^[[0m - [scheduler.py:104-do_s>
2024-10-16 11:34:59,926:engine:INFO - ^[[36m=== play('PlaylistItem [11:35:00 - 11:39:15 | 255.31sec | Source: ...file://3/6]') ===^[[0m - [scheduler.py:201-do_play()]
2024-10-16 11:34:59,927:engine:INFO - ^[[35mFade out channel [0 : in_queue_0]^[[0m - [channels.py:270-fade_out()]
2024-10-16 11:35:00,750:engine:ERROR - ^[[31mError setting volume of channel [0 : in_queue_0] to 58%: ready=false selected=true single=false volume=57% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:00,771:engine:ERROR - ^[[31mError setting volume of channel [0 : in_queue_0] to 57%: ready=false selected=true single=false volume=56% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:01,329:engine:ERROR - ^[[31mError setting volume of channel [0 : in_queue_0] to 29%: ready=false selected=true single=false volume=28% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:01,924:engine:INFO - ^[[35mReset active channel^[[0m - [mixer.py:133-set_active_channel()]
2024-10-16 11:35:01,925:engine:INFO - ^[[35mClearing channel [0 : in_queue_0] in 5 seconds^[[0m - [channels.py:408-flush_queue()]
2024-10-16 11:35:01,925:engine:INFO - ^[[35mFade in channel [1 : in_queue_1]^[[0m - [channels.py:249-fade_in()]
2024-10-16 11:35:02,476:engine:ERROR - ^[[31mError setting volume of channel [1 : in_queue_1] to 29%: ready=true selected=false single=false volume=28% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:03,026:engine:ERROR - ^[[31mError setting volume of channel [1 : in_queue_1] to 57%: ready=true selected=false single=false volume=56% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:03,045:engine:ERROR - ^[[31mError setting volume of channel [1 : in_queue_1] to 58%: ready=true selected=false single=false volume=57% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:03,885:engine:INFO - ^[[35mSet active channel to '[1 : in_queue_1]'^[[0m - [mixer.py:130-set_active_channel()]
2024-10-16 11:35:03,886:engine:INFO - PUT clock info to 'http://engine-api:8008/api/v1/clock':
{'engineSource': 1, 'currentTimeslot': {'timeslotId': '7683b173-1c7e-4a81-814f-7511855688de', 'timeslotStart': 1729071300.0, 'timeslotEnd': 1729071600.0, 'showId': 3, 'showName':>
2024-10-16 11:35:03,886:engine:INFO - Built JSON: {
    "currentTimeslot": {
        "playlistId": 5,
        "playlistType": 0,
        "showId": 3,
        "showName": "Test",
        "timeslotEnd": 1729071600.0,
        "timeslotId": "7683b173-1c7e-4a81-814f-7511855688de",
        "timeslotStart": 1729071300.0
    },

        "timeslotStart": 1729071300.0
    },
    "engineSource": 1,
    "plannedPlaylist": {
        "entries": [
            {
                "trackAlbum": "Cyberpunk 2077",
                "trackArtist": "Rezodrone, Jason Charles Miller & Jamison Boaz",
                "trackDuration": 255.312993,
                "trackNum": 1,
                "trackStart": 1729071300.0,
                "trackTitle": "RESIST AND DISORDER",
                "trackType": 0
            }
        ],
        "playlistId": 5
    },
    "upcomingTimeslots": [
        {
            "playlistId": -1,
            "playlistType": -1,
            "showId": 3,
            "showName": "Test",
            "timeslotEnd": 1729112400.0,
            "timeslotId": "41994e5d-6933-4eee-be74-5fc930db90f0",
            "timeslotStart": 1729111800.0
        },
        {
            "playlistId": -1,
            "playlistType": -1,
            "showId": 2,
            "showName": "fallback",
            "timeslotEnd": 1729155161.463053,
            "timeslotId": "fa634f26-3935-4305-9658-46397640bb23",
            "timeslotStart": 1729112400.0
        }
    ]
} - [api.py:184-serialize_json()]
2024-10-16 11:35:03,886:engine:INFO -

   SCHEDULED NOW:
┌----------------------------------------------------------------------------------------------------
│   Playing timeslot ID#f64b2efa-3e53-45b7-8839-376200d4b2f0: 11:30:00 - 22:50:00 [Show#2: fallback]
│      ^[[31mNo playlist assigned. Station fallback will take over.^[[0m
└----------------------------------------------------------------------------------------------------
   SCHEDULED NEXT:
┌----------------------------------------------------------------------------------------------------
│   Queued timeslot ID#41994e5d-6933-4eee-be74-5fc930db90f0: 22:50:00 - 23:00:00 [Show#3: Test]
│      └── ^[[36mPlaylistType.SHOW^[[0m: ID#2 | 216.58 seconds
│         └── Item 1 | PlaylistItem [22:50:00 - 22:53:36 | 216.58sec | Source: ...file://3/2]
└----------------------------------------------------------------------------------------------------

 - [scheduler.py:217-do_play()]
2024-10-16 11:35:03,891:engine:ERROR - ^[[31m400 | Error during PUT at 'http://engine-api:8008/api/v1/clock': BAD REQUEST^[[0m - [api.py:126-handle_response()]
2024-10-16 11:35:06,928:engine:INFO - ^[[35mCleared queue channel 'in_queue_0' with result 'OK'^[[0m - [channels.py:414-flush_queue()]
2024-10-16 11:35:14,426:engine:INFO - ^[[36m== start fetching new timeslots (every 30 seconds) ==^[[0m - [scheduler.py:296-run()]
2024-10-16 11:35:14,466:engine:INFO - ^[[32mFinished fetching current timeslots from API (4)^[[0m - [timetable.py:103-refresh()]
2024-10-16 11:35:14,467:engine:INFO - ^[[32mMerged timetable^[[0m - [timetable.py:122-merge_timetable()]
2024-10-16 11:35:14,470:engine:ERROR - ^[[31mUnexpected error while storing /tmp/timetable/timetable.json: 'NoneType' object is not iterable^[[0m - [timetable.py:146-persist_time>
2024-10-16 11:35:14,470:engine:INFO - Skip timeslot #41994e5d-6933-4eee-be74-5fc930db90f0 [22:50:00 - 23:00:00] - not in scheduling window T¹-60s to T²-60s - [timetable.py:259-ge>
2024-10-16 11:35:14,470:engine:INFO - Skip timeslot #83d58c6d-00e9-4de4-8e23-7cfb52525d8b [23:00:00 - 10:52:41] - not in scheduling window T¹-60s to T²-60s - [timetable.py:259-ge>
2024-10-16 11:35:14,470:engine:INFO - Skip timeslot #7e4b84b5-283f-41be-ab0e-cc6ca68dd5d5 [11:40:00 - 22:50:00] - not in scheduling window T¹-60s to T²-60s - [timetable.py:259-ge>
2024-10-16 11:35:14,470:engine:INFO - ^[[32mNo program to be queued.^[[0m - [scheduler.py:423-queue_program()]

Thanks @martina!

@Loxbie the following things should be investigated:

Multiple errors when setting the volume

2024-10-16 11:35:00,750:engine:ERROR - ^[[31mError setting volume of channel [0 : in_queue_0] to 58%: ready=false selected=true single=false volume=57% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:00,771:engine:ERROR - ^[[31mError setting volume of channel [0 : in_queue_0] to 57%: ready=false selected=true single=false volume=56% remaining=inf^[[0m - [mixe>
2024-10-16 11:35:01,329:engine:ERROR - ^[[31mError setting volume of channel [0 : in_queue_0] to 29%: ready=false selected=true single=false volume=28% remaining=inf^[[0m - [mixe>

The logs indicate a play-command at the expected time: 2024-10-16 11:34:59,926:engine:INFO - ^[[36m=== play('PlaylistItem [11:35:00 - 11:39:15 | 255.31sec | Source: ...file://3/6]') but it is not listed under "SCHEDULED NOW":

SCHEDULED NOW:
┌----------------------------------------------------------------------------------------------------
│   Playing timeslot ID#f64b2efa-3e53-45b7-8839-376200d4b2f0: 11:30:00 - 22:50:00 [Show#2: fallback]
│      ^[[31mNo playlist assigned. Station fallback will take over.^[[0m
└--------------------------------------------------------------------------------------------------

The cause of this error 2024-10-16 11:35:14,470:engine:ERROR - ^[[31mUnexpected error while storing /tmp/timetable/timetable.json: 'NoneType' object is not iterable^[[0m - [timetable.py:146-persist_time

I am assuming 2.) and 3.) go hand in hand.

Jup, I'm on it.

On that note, I already made a separate ticket for 1.). Look at #151 for more details on the issue.

marked this issue as related to #151

added To Do label

added Cycle [5/24] label

mentioned in commit 3569f7f1

mentioned in merge request !50 (merged)

As of now a workaround is in place with !50 (merged), I think we can move ahead for the release of %1.0-alpha5 — Capable Capybara . @david would you agree?

Yes, great, let's do that.

changed milestone to %1.0-alpha6 — Wondrous Whale

added Cycle [6/24] label

added discuss label

Let's discuss as part of alpha-6 how we are dealing with the missing virtual timeslots parts. Either we fix it as part of this ticket or we get rid of the engine-api virtual timeslot requirement, by implementing aura#312 and finalize other virtual timeslot handling details later.

Virtual Timeslots: Remove workarounds and replace with Steering's native approach

Parent: [EPIC] Display virtual timeslots / Music Fallba... (aura#176 - closed)

To be clarified

Dependencies

Designs

Child items ...

Activity