Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Choppy playback on Aether Cone #17

Closed
nano9g opened this issue Aug 5, 2023 · 4 comments
Closed

Choppy playback on Aether Cone #17

nano9g opened this issue Aug 5, 2023 · 4 comments

Comments

@nano9g
Copy link
Contributor

nano9g commented Aug 5, 2023 •
edited
Loading

Sorry to report that I've uncovered another problem while testing for #15. When I try to use SpotConnect to play to an Aether Cone, the audio is very choppy. In the log I don't see any actual errors, but appears to me that SpotConnect is constantly restarting the connection (and I could be reading it wrong).

The only difference with the Cone from my Apple devices is that it's on my IoT VLAN, however I have firewall rules in place that allow all communication from the Cone to the Raspberry Pi, and all devices from the main network are free to talk to the IoT network without restriction. I'm also able to AirPlay to the Cone from any Apple device on the main network as well as OwnTone hosted on the same Pi as SpotConnect without issue.

📃 Debug log of playback attempt 
$ ./spotraop-linux-aarch64-static -x ./spotraop-config.xml -d all=debug
[21:27:55.575498] main:1134 Starting spotraop version: v0.1.2 (Jul 26 2023 @ 18:40:52)

[21:27:55.585064] Start:903 Binding to [Main Network IP]
[21:27:55.586050] StartActiveRemote:788 DACP port: 50707
[21:27:55.674113] AddRaopDevice:514 [0xa56e10]: creating MAC
[21:27:55.674284] AddRaopDevice:528 [0xa56e10]: adding renderer (DEVF6GT4QEDWK3TEFQNZ@[IOT Network IP]) with mac AAAA-XXXXXXXX
[21:27:55.674584] raopcl_create:713 [0x7f84009610]: using ALAC coding
I BellHTTPServer.cpp:191: Server listening on port 0
I spotify.cpp:359: Server using actual port 35075
I MDNSService.cpp:181: using built-in mDNS for Shop Cone+
I spotify.cpp:381: Spotify client connected for Shop Cone+
D Session.cpp:63: Connecting with AP <ap-gue1.spotify.com:4070>
D PlainConnection.cpp:101: Connected to spotify server
I Session.cpp:39: Received APHello response
D Session.cpp:44: Received shannon keys
D Session.cpp:82: Authorization successful
I MercurySession.cpp:42: Received packet, command: 4
D TimeProvider.cpp:15: Time synced with spotify servers
I MercurySession.cpp:42: Received packet, command: 2
I MercurySession.cpp:42: Received packet, command: 118
D MercurySession.cpp:251: Executing Mercury Request, type SUB
D spotify.cpp:416: keepAlive Shop Cone+
I MercurySession.cpp:42: Received packet, command: 27
D MercurySession.cpp:153: Received country code US
I MercurySession.cpp:42: Received packet, command: 80
I MercurySession.cpp:42: Received packet, command: 31
I MercurySession.cpp:42: Received packet, command: 105
I MercurySession.cpp:42: Received packet, command: 181
I AccessKeyFetcher.cpp:99: Access token expired, fetching new one... 238
I MercurySession.cpp:42: Received packet, command: 74
I MercurySession.cpp:42: Received packet, command: 179
D MercurySession.cpp:174: Received mercury packet
D MercurySession.cpp:251: Executing Mercury Request, type SEND
D SpircHandler.cpp:59: Sent kMessageTypeHello!
I MercurySession.cpp:42: Received packet, command: 181
I MercurySession.cpp:42: Received packet, command: 181
D SpircHandler.cpp:67: Received subscription response
D SpircHandler.cpp:124: Notify frame
D SpircHandler.cpp:67: Received subscription response
D SpircHandler.cpp:124: Notify frame
I MercurySession.cpp:42: Received packet, command: 181
D SpircHandler.cppI MercurySession.cpp:67: Received subscription response
D SpircHandler.cpp:124: Notify frame
:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I AccessKeyFetcher.cpp:114: Access token sucessfully fetched
I MercurySession.cpp:42: Received packet, command: 181
D SpircHandler.cpp:67: Received subscription response
D SpircHandler.cpp:170: Load frame 3!
D MercurySession.cpp:251: Executing Mercury Request, type SEND
I TrackPlayer.cpp:94: Resetting state
D MercurySession.cpp:251: Executing Mercury Request, type GET
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I TrackQueue.cpp:158: Track name: Pergola
I TrackQueue.cpp:159: Track duration: 928143
D TrackQueue.cpp:161: trackInfo.restriction.size() = 1
D TrackQueue.cpp:212: File format: 2
D TrackQueue.cpp:212: File format: 1
D TrackQueue.cpp:212: File format: 0
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I MercurySession.cpp:42: Received packet, command: 13
I TrackQueue.cpp:252: Got audio key
I TrackQueue.cpp:275: Received access key, fetching CDN URL...
I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/c27f1826de3352b32952421744cd944675183a79?1691285283_mYyPHMIuCtNSfOjA1R60sZKT2K32GeFPNBT8ure2UZ4=
D MercurySession.cpp:251: Executing Mercury Request, type GET
I TrackPlayer.cpp:167: Got track ID=c27f1826de3352b32952421744cd944675183a79
I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-fa.scdn.co/audio/c27f1826de3352b32952421744cd944675183a79?1691285283_mYyPHMIuCtNSfOjA1R60sZKT2K32GeFPNBT8ure2UZ4=
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I TrackQueue.cpp:158: Track name: Ornamental Plants
I TrackQueue.cpp:159: Track duration: 907000
D TrackQueue.cpp:161: trackInfo.restriction.size() = 1
D TrackQueue.cpp:212: File format: 2
D TrackQueue.cpp:212: File format: 1
D TrackQueue.cpp:212: File format: 0
I MercurySession.cpp:42: Received packet, command: 13
I TrackQueue.cpp:252: Got audio key
I TrackQueue.cpp:275: Received access key, fetching CDN URL...
I CDNAudioFile.cpp:70: Header and footer bytes received
D MercurySession.cpp:251: Executing Mercury Request, type SEND
I spotify.cpp:235: new track will start at 0
[21:28:04.194216] shadowRequest:219 [0xa56e10]: spotify LOAD request
[21:28:04.297419] raopcl_connect:996 [0x7f84009610]: local interface [Main Network IP]
[21:28:04.298270] exec_request:614 [0x7f8400d9b0]: ----> : write POST /auth-setup RTSP/1.0
Content-Type: application/octet-stream
Content-Length: 33
CSeq: 1
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553

ŦB��%���q���=>��7:3���M O)�
I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/3545d5438c8e299f480ade315f657e455958f9d3?1691285284_fMCs1W-NsVkWdmknb5mafnChXVEZhHyDK8zVJxT2o74=
D MercurySession.cpp:251: Executing Mercury Request, type GET
[21:28:04.601102] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:04.601550] exec_request:650 [0x7f8400d9b0]: <------ : Content-Type: application/octet-stream
[21:28:04.601798] exec_request:650 [0x7f8400d9b0]: <------ : Content-Length: 1076
[21:28:04.602056] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:04.602185] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 1
[21:28:04.602262] exec_request:691 [0x7f8400d9b0]: Body data len 1076
0000  fc b2 40 66 bf e7 96 50 52 3b e6 a2 3f c4 37 83   @f   PR;  ? 7
0010  ba 60 5c 2b d1 90 03 a6 c8 03 ce 41 ba 96 70 3b  `\+       A  p;
0020  00 00 03 8c 30 82 03 88 06 09 2a 86 48 86 f7 0d     0     * H
0030  01 07 02 a0 82 03 79 30 82 03 75 02 01 01 31 00       y0  u   1
0040  30 0b 06 09 2a 86 48 86 f7 0d 01 07 01 a0 82 03 0   * H
0050  5d 30 82 03 59 30 82 02 41 a0 03 02 01 02 02 0f ]0  Y0  A
0060  12 12 aa 13 11 03 aa 06 aa 12 94 aa 96 69 51 30              iQ0
0070  0d 06 09 2a 86 48 86 f7 0d 01 01 05 05 00 30 81    * H        0
0080  83 31 0b 30 09 06 03 55 04 06 13 02 55 53 31 13  1 0   U    US1
0090  30 11 06 03 55 04 0a 13 0a 41 70 70 6c 65 20 49 0   U    Apple I
00a0  6e 63 2e 31 26 30 24 06 03 55 04 0b 13 1d 41 70 nc.1&0$  U    Ap
00b0  70 6c 65 20 43 65 72 74 69 66 69 63 61 74 69 6f ple Certificatio
00c0  6e 20 41 75 74 68 6f 72 69 74 79 31 37 30 35 06 n Authority1705
00d0  03 55 04 03 13 2e 41 70 70 6c 65 20 69 50 6f 64  U   .Apple iPod
00e0  20 41 63 63 65 73 73 6f 72 69 65 73 20 43 65 72  Accessories Cer
00f0  74 69 66 69 63 61 74 69 6f 6e 20 41 75 74 68 6f tification Autho
0100  72 69 74 79 30 1e 17 0d 31 33 31 31 30 33 30 37 rity0   13110307
0110  35 31 31 32 5a 17 0d 32 31 31 31 30 33 30 37 35 5112Z  211103075
0120  31 31 32 5a 30 70 31 0b 30 09 06 03 55 04 06 13 112Z0p1 0   U
0130  02 55 53 31 13 30 11 06 03 55 04 0a 0c 0a 41 70  US1 0   U    Ap
0140  70 6c 65 20 49 6e 63 2e 31 1f 30 1d 06 03 55 04 ple Inc.1 0   U
0150  0b 0c 16 41 70 70 6c 65 20 69 50 6f 64 20 41 63    Apple iPod Ac
0160  63 65 73 73 6f 72 69 65 73 31 2b 30 29 06 03 55 cessories1+0)  U
0170  04 03 0c 22 49 50 41 5f 31 32 31 32 41 41 31 33    "IPA_1212AA13
0180  31 31 30 33 41 41 30 36 41 41 31 32 39 34 41 41 1103AA06AA1294AA
0190  39 36 36 39 35 31 30 81 9f 30 0d 06 09 2a 86 48 9669510  0   * H
01a0  86 f7 0d 01 01 01 05 00 03 81 8d 00 30 81 89 02             0
01b0  81 81 00 aa a3 77 e5 3f 4f e6 08 9f c9 61 b1 5e      w ?O    a ^
01c0  b2 45 fa c0 e6 aa b9 62 63 cc 8c 5e e8 fd a7 43  E     bc  ^   C
01d0  29 4b 79 86 f3 d5 f3 ec ee 42 73 e9 1b 07 aa 26 )Ky      Bs    &
01e0  07 65 8e d0 14 47 c8 5f 7f 23 92 ea 81 27 d6 ce  e   G _ #   '
01f0  fe 61 d2 14 c3 69 52 7b 4d 50 7b fe 77 86 92 54  a   iR{MP{ w  T
0200  7f 3b d3 fa c8 f5 c6 c2 53 94 b0 e6 bd 6e 45 3f  ;      S    nE?
0210  e6 69 41 df 74 03 2c c8 fa 68 b2 45 ac 83 6c 6e  iA t ,  h E  ln
0220  cd 89 85 bb 9b b9 31 c8 74 82 6f 73 82 80 8d 8b       1 t os
0230  f4 d1 d7 02 03 01 00 01 a3 60 30 5e 30 1d 06 03          `0^0
0240  55 1d 0e 04 16 04 14 2a be 69 4e 08 d7 3f 9c be U      * iN  ?
0250  88 9a 11 e7 3a f5 54 1b 3c c1 c1 30 0c 06 03 55     : T <  0   U
0260  1d 13 01 01 ff 04 02 30 00 30 1f 06 03 55 1d 23        0 0   U #
0270  04 18 30 16 80 14 ff 4b 1a 43 9a f5 19 96 ab 18   0    K C
0280  00 2b 61 c9 ee 40 9d 8e c7 04 30 0e 06 03 55 1d  +a  @    0   U
0290  0f 01 01 ff 04 04 03 02 03 b8 30 0d 06 09 2a 86           0   *
02a0  48 86 f7 0d 01 01 05 05 00 03 82 01 01 00 19 0c H
02b0  bc 8d 27 ff bd c1 a7 9d b3 49 93 fe 38 41 a7 39   '      I  8A 9
02c0  75 30 41 38 03 86 5e ec d2 6e 93 1d 26 81 cb 8c u0A8  ^  n  &
02d0  05 04 91 70 bd 87 b5 67 85 15 5f 29 c6 3d e4 56    p   g  _) = V
02e0  1d db de ff c6 92 27 f5 42 ce 5a 64 0f ee 73 9b       ' B Zd  s
02f0  a0 99 4c d9 03 89 b6 1b 12 00 11 b6 68 dd f3 9a   L         h
0300  2a ca 34 f3 81 36 35 af 95 dd 73 bf df 62 af 2f * 4  65   s  b /
0310  f0 8d 8b eb bb 35 79 9c 33 57 49 ca 5e a7 7d 48      5y 3WI ^ }H
0320  90 d8 d9 d3 f4 45 c2 29 82 df 0d 9e ad af 87 47      E )       G
0330  61 f9 e2 c3 e5 f7 ec 2e a2 8b 44 51 a5 21 04 81 a      .  DQ !
0340  7f 60 7a 6b 9c 62 69 52 58 d1 f6 34 f8 dc c1 84  `zk biRX  4
0350  ba 0f 83 98 c2 1c 85 eb 2d 6f ca c1 1e ad 61 62         -o    ab
0360  33 05 d3 09 49 fb bc 06 3c 88 ba 53 53 c5 21 f1 3   I   <  SS !
0370  f1 09 86 ef 11 b0 fd df 53 90 04 5b 73 ac c1 b2         S  [s
0380  b4 f3 5a 34 1d 37 d4 a1 79 b4 6c 91 69 21 b5 46   Z4 7  y l i! F
0390  b8 1f a5 1d 20 92 25 14 e8 d0 37 83 07 23 58 a8       %   7  #X
03a0  85 a9 cc bc 11 74 ee bb 5b 65 8f 89 26 1f 31 00      t  [e  & 1
03b0  00 00 00 80 a9 06 1f 29 0d 72 79 6d 3d 0b 23 ff        ) rym= #
03c0  d3 93 82 f6 d3 51 54 4d 00 1d 58 40 15 d7 4b f7      QTM  X@  K
03d0  66 43 2c 37 42 74 21 e7 d8 43 31 f9 6b 06 8a 89 fC,7Bt!  C1 k
03e0  de e1 f9 49 01 56 af 7d 5d 91 06 c8 e0 a9 ec b4    I V }]
03f0  b9 c1 84 ca 69 3d 41 bb d4 dd 6d ed a7 2f 71 df     i=A   m  /q
0400  97 82 b8 d2 2a a4 cf df 49 59 72 35 2c fc 30 c7     *   IYr5, 0
0410  40 c0 cc c0 38 dc db c5 fb eb 90 2d 37 d5 18 0b @   8      -7
0420  a5 8f 15 cc a5 6f fb e2 81 32 37 04 17 f3 4d 3a      o   27   M:
0430  92 21 cb 8d  !
[21:28:04.645279] exec_request:614 [0x7f8400d9b0]: ----> : write ANNOUNCE rtsp://[IOT Network IP]/3344080965 RTSP/1.0
Content-Type: application/sdp
Content-Length: 178
CSeq: 2
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553

v=0
o=iTunes 3344080965 0 IN IP4 [Main Network IP]
s=iTunes
c=IN IP4 [IOT Network IP]
t=0 0
m=audio 0 RTP/AVP 96
a=rtpmap:96 AppleLossless
a=fmtp:96 352 0 16 40 10 14 2 255 0 0 44100

[21:28:04.648285] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:04.648547] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:04.648677] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 2
[21:28:04.648829] exec_request:614 [0x7f8400d9b0]: ----> : write SETUP rtsp://[IOT Network IP]/3344080965 RTSP/1.0
Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=49886;timing_port=43285
CSeq: 3
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553


[21:28:04.655436] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:04.656349] exec_request:650 [0x7f8400d9b0]: <------ : Transport: RTP/AVP/UDP;unicast;mode=record;server_port=34139;control_port=33160;timing_port=33028
[21:28:04.656505] exec_request:650 [0x7f8400d9b0]: <------ : Session: 1
[21:28:04.656923] exec_request:650 [0x7f8400d9b0]: <------ : Audio-Jack-Status: connected; type=analog
[21:28:04.657194] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:04.657323] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 3
[21:28:04.657393] rtspcl_setup:239 [0x7f8400d9b0]: <------ : session:1
[21:28:04.657445] raopcl_connect:1058 [0x7f84009610]:opened audio socket   l:48516 r:34139
[21:28:04.657491] raopcl_connect:1059 [0x7f84009610]:opened timing socket  l:43285 r:33028
[21:28:04.657534] raopcl_connect:1060 [0x7f84009610]:opened control socket l:49886 r:33160
[21:28:04.657618] exec_request:614 [0x7f8400d9b0]: ----> : write RECORD rtsp://[IOT Network IP]/3344080965 RTSP/1.0
Range: npt=0-
RTP-Info: seq=9159;rtptime=4058685655
CSeq: 4
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1


[21:28:04.661339] _rtp_timing_thread:1296 [0x7f84009610]: NTP remote port: 33028
[21:28:04.661560] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198884.2841125161 (ref 2208988800.1107725339)
[21:28:04.664119] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198884.2852257716 (ref 1691198884.2849415967)
[21:28:04.667223] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198884.2865589294 (ref 1691198884.2862643737)
[21:28:04.766220] ActiveRemoteThread:634 raw active remote: get /ctrl-int/1/setproperty?dmcp.device-volume=-20.7525749 http/1.1
host: [raspberry pi].local
active-remote: 3948577553
user-agent: airplay/190.9


I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I TrackQueue.cpp:158: Track name: Reincarnation At The End Of The World
I TrackQueue.cpp:159: Track duration: 1364000
D TrackQueue.cpp:161: trackInfo.restriction.size() = 1
D TrackQueue.cpp:212: File format: 2
D TrackQueue.cpp:212: File format: 1
D TrackQueue.cpp:212: File format: 0
I MercurySession.cpp:42: Received packet, command: 13
I TrackQueue.cpp:252: Got audio key
I TrackQueue.cpp:275: Received access key, fetching CDN URL...
I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/409a5d22214777ad7587b0da207285c00a387eae?1691285285_306omyX4yqozYDOfAh5rxiCqF8Yc4Dz9AnsWnDlJu70=
[21:28:05.452728] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:05.453309] exec_request:650 [0x7f8400d9b0]: <------ : Audio-Latency: 0
[21:28:05.453871] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:05.454150] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 4
[21:28:05.454601] raopcl_connect:1080 [0x7f84009610]: setting volume as part of connect -30.00
[21:28:05.454815] exec_request:614 [0x7f8400d9b0]: ----> : write SET_PARAMETER rtsp://[IOT Network IP]/3344080965 RTSP/1.0
Content-Type: text/parameters
Content-Length: 20
CSeq: 5
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1

volume: -30.000000

[21:28:05.477135] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:05.477796] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:05.478122] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 5
[21:28:05.478333] ActiveRemoteThread:668 [0xa56e10]: remote command setproperty?dmcp.device-volume=-20.7525749
[21:28:05.478511] ActiveRemoteThread:726 [0xa56e10]: volume feedback 0 (-20.75)
D MercurySession.cpp:251: Executing Mercury Request, type SEND
D MercurySession.cpp:251: Executing Mercury Request, type SEND
[21:28:05.479385] exec_request:614 [0x7f8400d9b0]: ----> : write SET_PARAMETER rtsp://[IOT Network IP]/3344080965 RTSP/1.0
Content-Type: text/parameters
Content-Length: 20
CSeq: 6
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1

volume: -20.752575

[21:28:05.521547] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:05.522231] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:05.522557] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 6
[21:28:05.523027] shadowRequest:223 [0xa56e10]: spotify play request
[21:28:05.601976] ActiveRemoteThread:634 raw active remote: get /ctrl-int/1/setproperty?dmcp.device-busy=0 http/1.1
host: [raspberry pi].local
active-remote: 3948577553
user-agent: airplay/190.9


[21:28:05.602385] ActiveRemoteThread:668 [0xa56e10]: remote command setproperty?dmcp.device-busy=0
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I TrackPlayer.cpp:200: Playing
I spotify.cpp:133: trackUniqueId update  => c27f1826de3352b32952421744cd944675183a79
[21:28:05.934767] raopcl_accept_frames:416 [0x7f84009610]: begining to stream hts:0 n:1691198885.4014767924
[21:28:05.935150] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198885.4014669824 (ts:74581870869722)
[21:28:05.935222] raopcl_accept_frames:424 [0x7f84009610]: restarting w/o pause n:1691198885.4014767924, hts:74581870869722
[21:28:06.455771] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198886.1845166080 (ts:74581870891546)
[21:28:06.886847] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198886.3808570839 (ref 1691198886.3798241758)
D MercurySession.cpp:251: Executing Mercury Request, type SEND
I spotify.cpp:249: Got next track id 1cb15c0187f740ddb46ebd3c2c263261 => <Pergola>
[21:28:07.074198] exec_request:614 [0x7f8400d9b0]: ----> : write SET_PARAMETER rtsp://[IOT Network IP]/3344080965 RTSP/1.0
RTP-Info: rtptime=4058791610
Content-Type: application/x-dmap-tagged
Content-Length: 91
CSeq: 7
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1

mlit
[21:28:07.081482] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:07.081747] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:07.081878] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 7
I spotify.cpp:169: Setting track position 420947 / 928143
[21:28:07.111256] exec_request:614 [0x7f8400d9b0]: ----> : write SET_PARAMETER rtsp://[IOT Network IP]/3344080965 RTSP/1.0
Content-Type: text/parameters
Content-Length: 44
CSeq: 8
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1

progress: 4040230090/4058793852/4081161195

[21:28:07.113592] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:07.113831] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:07.113937] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 8
D MercurySession.cpp:251: Executing Mercury Request, type SEND
[21:28:07.180390] exec_request:614 [0x7f8400d9b0]: ----> : write SET_PARAMETER rtsp://[IOT Network IP]/3344080965 RTSP/1.0
RTP-Info: rtptime=4058796186
Content-Type: image/jpeg
Content-Length: 24124
CSeq: 9
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1

����
[21:28:07.189601] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:07.189845] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:07.189952] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 9
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
I MercurySession.cpp:42: Received packet, command: 178
D MercurySession.cpp:174: Received mercury packet
[21:28:07.457212] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198887.1903951872 (ts:74581870936250)
[21:28:08.458349] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198888.1791361024 (ts:74581870979194)
[21:28:08.769560] raopcl_send_chunk:588 [0x7f84009610]: check n:3276741441 p:3276742674 ts:74581870994330 sn:9512
               retr: 0, avail: 0, send: 0, select: 0)
[21:28:09.143013] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198889.614103013 (ref 1691198889.610267064)
[21:28:09.459484] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198889.1850212352 (ts:74581871023898)
[21:28:10.460601] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198890.1806172160 (ts:74581871067546)
[21:28:11.461743] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198891.1796472832 (ts:74581871111546)
[21:28:11.600790] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198891.2580235962 (ref 1691198891.2576740375)
[21:28:12.462945] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198892.1820983296 (ts:74581871155898)
[21:28:13.464149] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198893.1982660608 (ts:74581871201658)
[21:28:14.010107] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198894.43276090 (ref 1691198894.38555406)
[21:28:14.465285] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198894.1938620416 (ts:74581871245306)
[21:28:15.466418] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198895.1963196416 (ts:74581871289658)
[21:28:16.064293] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198896.275998893 (ref 1691198896.271382123)
[21:28:16.467562] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198896.1953431552 (ts:74581871333658)
I MercurySession.cpp:42: Received packet, command: 181
D SpircHandler.cpp:67: Received subscription response
D SpircHandler.cpp:124: Notify frame
[21:28:17.468702] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198897.1806565376 (ts:74581871376250)
D spotify.cpp:416: keepAlive Shop Cone+
[21:28:18.168598] exec_request:614 [0x7f8400d9b0]: ----> : write OPTIONS * RTSP/1.0
CSeq: 10
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1


[21:28:18.172062] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:18.174467] exec_request:650 [0x7f8400d9b0]: <------ : Public: ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER, POST, GET
[21:28:18.175057] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:18.175339] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 10
[21:28:18.469920] _raopcl_send_sync:1254 [0x7f84009610]: sync ntp:1691198898.1831141376 (ts:74581871420602)
I MercurySession.cpp:42: Received packet, command: 181
D SpircHandler.cpp:67: Received subscription response
D SpircHandler.cpp:124: Notify frame
D SpircHandler.cpp:129: Another player took control, pausing playback
I TrackPlayer.cpp:94: Resetting state
I TrackPlayer.cpp:249: Playing done
I spotify.cpp:104: Disconnecting Shop Cone+
[21:28:18.872004] _rtp_timing_thread:1328 [0x7f84009610]: NTP sync: 1691198898.3744769100 (ref 1691198898.3739876832)
[21:28:19.873379] exec_request:614 [0x7f8400d9b0]: ----> : write FLUSH rtsp://[IOT Network IP]/3344080965 RTSP/1.0
RTP-Info: seq=10737;rtptime=4059297435
CSeq: 11
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1


[21:28:19.876443] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:19.876759] exec_request:650 [0x7f8400d9b0]: <------ : RTP-Info: rtptime=4059297082
[21:28:19.877018] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:19.877184] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 11
[21:28:19.877287] exec_request:614 [0x7f8400d9b0]: ----> : write TEARDOWN rtsp://[IOT Network IP]/3344080965 RTSP/1.0
CSeq: 12
User-Agent: iTunes/7.6.2 (Windows; N;)
Client-Instance: 5ca4b754d44c9e31
DACP-ID: 1A2B3D4EA1B2C3D4
Active-Remote: 3948577553
Session: 1


[21:28:19.943297] exec_request:640 [0x7f8400d9b0]: <------ : 200: request ok
[21:28:19.943569] exec_request:650 [0x7f8400d9b0]: <------ : Server: AirTunes/190.9
[21:28:19.943708] exec_request:650 [0x7f8400d9b0]: <------ : CSeq: 12
I TrackPlayer.cpp:94: Resetting state
I MercurySession.cpp:128: Disconnecting mercury session
I PlainConnection.cpp:197: Closing socket...
E PlainConnection.cpp:146: Connection lost, will need to reconnect...
E MercurySession.cpp:53: Error while receiving packet: Reconnection required
I spotify.cpp:441: disconnecting player Shop Cone+
exit
[21:28:22.872647] main:1252 stopping cspot devices ...
[21:28:22.872716] main:1254 stopping Raop devices ...
[21:28:22.872742] Stop:926 terminate search thread ...
[21:28:22.906509] Stop:935 flush renderers ...
Segmentation fault

As always, I'm happy to provide more information!
@nano9g nano9g mentioned this issue Aug 5, 2023
Open
@philippe44
Copy link
Owner

Thanks for reporting that as well and thanks for taking the time to test (and I know it can be painful...)

@nano9g
Copy link
Contributor Author

nano9g commented Aug 5, 2023

I forgot to mention that I tried <encryption>1</encryption> and <alac_encode>0</alac_encode>. Neither seemed to help.

@philippe44
Copy link
Owner

Oh, can you try the read_ahead parameter in the config file and set it to 2000?

@nano9g
Copy link
Contributor Author

nano9g commented Aug 6, 2023

<read_ahead>2000</read_ahead> in the <device> config for the Cone fixed it!

@nano9g nano9g closed this as completed Aug 6, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@philippe44 @nano9g