Home of the Squeezebox™ & Transporter® network music players.
Page 2 of 3 FirstFirst 123 LastLast
Results 11 to 20 of 21
  1. #11
    Senior Member
    Join Date
    Jan 2010
    Posts
    508
    It happened again this morning and here is the server.log with debug messages for slimproto and the Radio's /var/log/messages file.
    There are 3 players involved (I modified the mac addresses in the files accordingly): TOUCH1 (wired), RADIO1 (wireless) and RADIO2 (wireless).
    The LMS server pc that was woken up by a scheduled task at ~05:45 has IP address of 192.168.2.100, the players have *.104, *.105 and *.106.

    RADIO1 is the one that I've switched on in the morning at ~05:56 and selected a local music album to play (the new Roger Waters album, btw).
    The music stopped playing either before the 4th track started at ~06:07 or shortly after. I marked some events in the server log (using a ##### prefix).

    If I interpret the messages correctly then the server was still sending data to the Radio (which was also shown in LMS WebUi) and even the Radio's messages file seem to indicate that data was received.

    Is anybody able to find some hints for the problem in the files, please?

    messages(Radio1).txt
    server(slimproto-debug).zip

  2. #12
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    14,817
    Quote Originally Posted by reinholdk View Post
    It happened again this morning and here is the server.log with debug messages for slimproto and the Radio's /var/log/messages file.
    There are 3 players involved (I modified the mac addresses in the files accordingly): TOUCH1 (wired), RADIO1 (wireless) and RADIO2 (wireless).
    The LMS server pc that was woken up by a scheduled task at ~05:45 has IP address of 192.168.2.100, the players have *.104, *.105 and *.106.

    RADIO1 is the one that I've switched on in the morning at ~05:56 and selected a local music album to play (the new Roger Waters album, btw).
    The music stopped playing either before the 4th track started at ~06:07 or shortly after. I marked some events in the server log (using a ##### prefix).

    If I interpret the messages correctly then the server was still sending data to the Radio (which was also shown in LMS WebUi) and even the Radio's messages file seem to indicate that data was received.

    Is anybody able to find some hints for the problem in the files, please?

    messages(Radio1).txt
    server(slimproto-debug).zip
    The logs show that radio was receiving data and decoding it into an output buffer right up to the end of the log. There is no indication of any breakdown in communication.

    When you say " music stopped playing" - do you mean the audio stop (as if muted) or did the "Now playing" screen also show stopped and not playing and did elapsed time counterprogress bar also stop.

  3. #13
    Senior Member
    Join Date
    Jan 2010
    Posts
    508
    Quote Originally Posted by bpa View Post
    When you say " music stopped playing" - do you mean the audio stop (as if muted) or did the "Now playing" screen also show stopped and not playing and did elapsed time counterprogress bar also stop.
    The audio output of the Radio stopped.
    As mentioned, the "Now playing" screen doesn't work at all in those situations. After turning the Radio on from stand-by mode and selecting an album to play, it shows correct information only for a second or two and then it displays the information of what has been played before switching the Radio off (to stand-by) and it doesn't display progress although the music is playing for ~10-15 minutes.

  4. #14
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    14,817
    You cut off the LMS log compared to the RAdio log. The Radio log showed request for 8 Audio tracks - last one at 6:36 (with realistic time gaps to imply they have been played) but LMS log you supplied stops at 6:15:00. I'd like to have seen LMS logs up to same time.
    As the content of slimproto messages are not that important at the moment you can set slimproto log to INFO rather than DEBUG.

    It looks like a Radio issue but I'm not sure what other radio logging should be enabled - something relating to audio output.
    Do you have any applets installed in Radio (e.g. custom clock) ?

    Code:
    Jun 12 05:58:22 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:02:49 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:02:49 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:07:02 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:07:02 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:13:50 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:13:50 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:18:48 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:18:48 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:24:43 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:24:43 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:30:14 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:30:14 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M
    Jun 12 06:36:23 squeezeplay: INFO   audio.decode - decode_start_handler:279 init decoder flc
    Jun 12 06:36:23 squeezeplay: INFO   audio.decode - Playback.lua:476 connect 192.168.2.100:9000 GET /stream.mp3?player=00:04:20:RADIO1 HTTP/1.0^M

  5. #15
    Senior Member
    Join Date
    Jan 2010
    Posts
    508
    Thanks for your effort so far, bpa!

    The LMS log is shorter because Radio stopped audio output before - either during the 3rd or 4th track. A few minutes later (cause if it happens, I'm usually in the shower and I feel a real pain when the music stops ) I went to the LMS PC, copied the server log and checked various other details before I copied the messages file over from the Radio.

    But if you really want to have another look, here is the server.log up to the start of the 10th track:
    server(slimproto-debug2).zip

    I had to check for the applets, cause I wasn't aware: I had two applets installed in both Radios: bluegaspode's Weather Forecast and erland's Patch Installer (the latter indicated that an update was available). Now I uninstalled both.

    Note that when the problem occurs, often both Radios are affected!

  6. #16
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    14,817
    Quote Originally Posted by reinholdk View Post
    Thanks for your effort so far, bpa!

    The LMS log is shorter because Radio stopped audio output before - either during the 3rd or 4th track. A few minutes later (cause if it happens, I'm usually in the shower and I feel a real pain when the music stops ) I went to the LMS PC, copied the server log and checked various other details before I copied the messages file over from the Radio.

    But if you really want to have another look, here is the server.log up to the start of the 10th track:
    server(slimproto-debug2).zip

    I'll have a look. Sometimes what is missing in logs is important so it possible after audio stops the LMS loks for eachtrack is different and so it may give a hint as to what has changed.


    pquote]I had to check for the applets, cause I wasn't aware: I had two applets installed in both Radios: bluegaspode's Weather Forecast and erland's Patch Installer (the latter indicated that an update was available). Now I uninstalled both.
    Patch installer will be quiet when playing but Weather forecast could do stuff at any time.

    Note that when the problem occurs, often both Radios are affected!
    Are the Radios synced ?
    If not synced and affect both radios at the same time - is the Touch unaffected ?

  7. #17
    Senior Member
    Join Date
    Jan 2010
    Posts
    508
    no and no: the radios are not synced and the touch is not affected.

    edit: I meant no and yes
    Last edited by reinholdk; 2017-06-15 at 12:54.

  8. #18
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    14,817
    Quote Originally Posted by reinholdk View Post
    no and no: the radios are not synced and the touch is not affected.

    edit: I meant no and yes
    It is strange that only the Radio are affected and not Touch since they use the same LMS code.
    From the logs the Radios still appear to LMS to bve playing tracks well after teh audio stops and the Now Play screen stop. I think you need to enable more logging on the player.

    Initial suggestions:
    audio.output to DEBUG
    applet.NowPlaying to DEBUG

    audio.decode set to DEBUG would give extra info such as the fullness of the buffer as track is played and volume control changes but I'm not sure at this stage it it is useful.

  9. #19
    Senior Member
    Join Date
    Jan 2010
    Posts
    508
    Quote Originally Posted by bpa View Post
    Initial suggestions:
    audio.output to DEBUG
    applet.NowPlaying to DEBUG
    Did that. Will report back when the problem occurs again.

    In the meanwhile: is there a way to configure the time span for which the /var/log/messages file is storing the messages or to configure the number of files that are kept. Currently there are two and this might be not sufficient.

  10. #20
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    14,817
    Quote Originally Posted by reinholdk View Post
    Did that. Will report back when the problem occurs again.

    In the meanwhile: is there a way to configure the time span for which the /var/log/messages file is storing the messages or to configure the number of files that are kept. Currently there are two and this might be not sufficient.
    No - the usual way to keep a constant log is to ssh into the Radio and then do a "tail -f /var/log/messages" saving output into a file

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •