1696 caused 100% CPU usage on XP SP2

Viewing 15 posts - 1 through 15 (of 22 total)
  • Author
    Posts
  • #1906
    Anonymous
    Inactive

    hi

    just to say, after install I experienced this. The service had been shut down and started a few times and I then left the server running and tested it from a few different clients.

    I think the problem could have been caused due to the loss of network connection that the server experienced while it was serving. It automatically recovered when the network came back but then seemed to exhibit this effect. After a service restart some hours later, it initially peaked at 100% again but went down to a normal level.

    This may be of no help… but if you want any more info let me know.

    Btw, this was my first install of the software ever so there was no upgrade issues here.

    arkid

    #14191
    rpedde
    Participant

    @arkid77 wrote:

    hi

    just to say, after install I experienced this. The service had been shut down and started a few times and I then left the server running and tested it from a few different clients.

    I think the problem could have been caused due to the loss of network connection that the server experienced while it was serving. It automatically recovered when the network came back but then seemed to exhibit this effect. After a service restart some hours later, it initially peaked at 100% again but went down to a normal level.

    This may be of no help… but if you want any more info let me know.

    Btw, this was my first install of the software ever so there was no upgrade issues here.

    arkid

    The initial file scan is pretty cpu intensive, so that’s probably what that was.

    As far as it going to 100% when the network connection dies, that’s interesting… I might not be detecting a closed connection well, and might be trying to continue to push data through the closed socket. I’ll see if I can replicate this by unplugging a nic while streaming.

    — Ron

    #14192
    Anonymous
    Inactive

    @rpedde wrote:

    The initial file scan is pretty cpu intensive, so that’s probably what that was.

    As far as it going to 100% when the network connection dies, that’s interesting… I might not be detecting a closed connection well, and might be trying to continue to push data through the closed socket. I’ll see if I can replicate this by unplugging a nic while streaming.

    — Ron

    Hi

    Thanks, that would be great to test. This activity was definitely not desirable and I encountered 3/4 hours after the server had first been installed. The service was problably on its 3rd or 4th session of having ever run.

    The 100% activity was constant. I realised something was wrong as my laptop was huffing and puffing so loud and normally I hardly ever hear its fan due to its low heat mobile cpu.

    A

    #14193
    dantidote
    Participant

    Yup same problem here, It will run for a while just fine, then my server will just ramp up to 100% and eventually die.

    #14194
    Anonymous
    Inactive

    I just want to confirm that I have this same 100% CPU issue. I can’t really pinpoint when it happens; obviously I get high CPU usage when other people connect and it starts transcoding FLAC stuff, but even when no one is connected and listening to music, it still bumps up to max CPU usage (on both cores). Since it’s hard to pinpoint when it happens, and I’m not always paying attention to my server, I’ll often come back hours later and it will be at 100% and I won’t be sure why.

    #14195
    Zachary
    Participant

    I haven’t noticed this yet, and I’m on svn-1696 as well. My processor load runs at 16% right now steadily, and only that because I’ve got Oddcast streaming Pandora 😀 I’ll keep an eye out for things, though.

    Thanks,

    Zachary

    #14196
    rpedde
    Participant

    @redbeard wrote:

    I just want to confirm that I have this same 100% CPU issue. I can’t really pinpoint when it happens; obviously I get high CPU usage when other people connect and it starts transcoding FLAC stuff, but even when no one is connected and listening to music, it still bumps up to max CPU usage (on both cores). Since it’s hard to pinpoint when it happens, and I’m not always paying attention to my server, I’ll often come back hours later and it will be at 100% and I won’t be sure why.

    Might be the same thing — a client disconnecting in the middle of a song, and it keeps trying to pump data at it.

    At least, that’s what seems likely now. I just re-installed my laptop with Leopard (from scratch), so don’t have a windows dev vm up yet, hope to tonight or tomorrow, and then I’ll be able to take a closer look at this.

    — Ron

    #14197
    Anonymous
    Inactive

    I left it running all night and all today. When I woke up it was fine, but when I got home from class it was doing it again. I had the logs running on verbosity level 8, and using a rough estimate from the amount of CPU time firefly.exe has used, I think the time frame below is roughly about when it started. I cut out all of the “unknown meta code” stuff that happens all the time, and there’s a lot more of similar logs after this as the day progressed. I’m also on a college network, and I’m starting to have a weird suspicion that this is happening perhaps as a result of people using mytunes or ourtunes or something similar to attempt to download the music off me.


    2007-11-05 14:15:27 (b49e01c5): Request: GET daap://146.244.184.248:9999/databases/1/items/1036.wav HTTP/1.1

    2007-11-05 14:15:27 (b49e01c5): Session 0: Streaming file '1_1.4_14. Harder, Better, Faster, Stronger.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:17:53 (b49e01c5): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:17:53 (def9d5db): Request: GET daap://146.244.184.248:9999/databases/1/items/1034.wav HTTP/1.1

    2007-11-05 14:17:53 (def9d5db): Session 0: Streaming file '1_1.2_14. Aerodynamic.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:17:53 (def9d5db): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:17:53 (b49e8e26): Request: GET daap://146.244.184.248:9999/databases/1/items/1034.wav HTTP/1.1

    2007-11-05 14:17:53 (b49e8e26): Session 0: Streaming file '1_1.2_14. Aerodynamic.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:19:21 (b49e8e26): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:19:21 (defa623c): Request: GET daap://146.244.184.248:9999/databases/1/items/1061.wav HTTP/1.1

    2007-11-05 14:19:21 (defa623c): Session 0: Streaming file '1_1.5_10. Make Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:19:22 (defa623c): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:19:22 (b49f1a87): Request: GET daap://146.244.184.248:9999/databases/1/items/1061.wav HTTP/1.1

    2007-11-05 14:19:22 (b49f1a87): Session 0: Streaming file '1_1.5_10. Make Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:24:19 (defaee9d): Request: GET daap://146.244.184.248:9999/databases/1/items/1062.wav HTTP/1.1

    2007-11-05 14:24:19 (defaee9d): Session 0: Streaming file '1_1.6_10. The Brainwasher.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:24:50 (b0ae96e3): Rescanning database
    2007-11-05 14:24:56 (b0ae96e3): Starting playlist scan
    2007-11-05 14:24:56 (b0ae96e3): Updating playlists
    2007-11-05 14:24:56 (b0ae96e3): Scanned 4249 songs (was 4249) in 6 seconds
    2007-11-05 14:25:29 (defaee9d): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:25:29 (b49fa6e8): Request: GET daap://146.244.184.248:9999/databases/1/items/1059.wav HTTP/1.1

    2007-11-05 14:25:29 (b49fa6e8): Session 0: Streaming file '1_1.3_10. Robot Rock.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:25:30 (b49fa6e8): Error writing to client socket: An established connection was aborted by the software in your host machine.
    2007-11-05 14:25:30 (defb7afe): Request: GET daap://146.244.184.248:9999/databases/1/items/1059.wav HTTP/1.1

    2007-11-05 14:25:30 (defb7afe): Session 0: Streaming file '1_1.3_10. Robot Rock.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:30:15 (defc075f): Request: GET daap://146.244.184.248:9999/databases/1/items/1060.wav HTTP/1.1

    2007-11-05 14:30:15 (defc075f): Session 0: Streaming file '1_1.4_10. Steam Machine.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:35:35 (defc93c0): Request: GET daap://146.244.184.248:9999/databases/1/items/1061.wav HTTP/1.1

    2007-11-05 14:35:35 (defc93c0): Session 0: Streaming file '1_1.5_10. Make Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:38:59 (defc93c0): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:38:59 (defd2021): Request: GET daap://146.244.184.248:9999/databases/1/items/1033.wav HTTP/1.1

    2007-11-05 14:38:59 (defd2021): Session 0: Streaming file '1_1.1_14. One More Time.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:38:59 (defd2021): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:38:59 (defdac82): Request: GET daap://146.244.184.248:9999/databases/1/items/1033.wav HTTP/1.1

    2007-11-05 14:38:59 (defdac82): Session 0: Streaming file '1_1.1_14. One More Time.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:44:18 (defe38e3): Request: GET daap://146.244.184.248:9999/databases/1/items/1034.wav HTTP/1.1

    2007-11-05 14:44:18 (defe38e3): Session 0: Streaming file '1_1.2_14. Aerodynamic.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:47:47 (defec544): Request: GET daap://146.244.184.248:9999/databases/1/items/1035.wav HTTP/1.1

    2007-11-05 14:47:47 (defec544): Session 0: Streaming file '1_1.3_14. Digital Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:52:44 (deff51a5): Request: GET daap://146.244.184.248:9999/databases/1/items/1036.wav HTTP/1.1

    2007-11-05 14:52:44 (deff51a5): Session 0: Streaming file '1_1.4_14. Harder, Better, Faster, Stronger.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:53:40 (deff51a5): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:53:40 (e942016d): Thread 176: could not read: unknown internal error
    2007-11-05 15:24:58 (b0ae96e3): Rescanning database
    2007-11-05 15:25:04 (b0ae96e3): Starting playlist scan
    2007-11-05 15:25:04 (b0ae96e3): Updating playlists
    2007-11-05 15:25:04 (b0ae96e3): Scanned 4249 songs (was 4249) in 6 seconds
    2007-11-05 16:16:14 (e9428dce): Request: GET daap://146.244.184.248:9999/databases/1/items/443.wav HTTP/1.1

    2007-11-05 16:16:14 (e9428dce): Session 0: Streaming file '1_1.5_12. Drown Me Slowly.flac' to 146.244.184.26 (offset 0)
    2007-11-05 16:17:20 (e9428dce): Error writing to client socket: An established connection was aborted by the software in your host machine.
    2007-11-05 16:17:28 (deffde06): Thread 193: could not read: Unknown error
    2007-11-05 16:18:16 (b4a03349): Thread 185: could not read: unknown internal error
    #14198
    rpedde
    Participant

    @redbeard wrote:

    I left it running all night and all today. When I woke up it was fine, but when I got home from class it was doing it again. I had the logs running on verbosity level 8, and using a rough estimate from the amount of CPU time firefly.exe has used, I think the time frame below is roughly about when it started. I cut out all of the “unknown meta code” stuff that happens all the time, and there’s a lot more of similar logs after this as the day progressed. I’m also on a college network, and I’m starting to have a weird suspicion that this is happening perhaps as a result of people using mytunes or ourtunes or something similar to attempt to download the music off me.


    2007-11-05 14:15:27 (b49e01c5): Request: GET daap://146.244.184.248:9999/databases/1/items/1036.wav HTTP/1.1

    2007-11-05 14:15:27 (b49e01c5): Session 0: Streaming file '1_1.4_14. Harder, Better, Faster, Stronger.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:17:53 (b49e01c5): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:17:53 (def9d5db): Request: GET daap://146.244.184.248:9999/databases/1/items/1034.wav HTTP/1.1

    2007-11-05 14:17:53 (def9d5db): Session 0: Streaming file '1_1.2_14. Aerodynamic.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:17:53 (def9d5db): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:17:53 (b49e8e26): Request: GET daap://146.244.184.248:9999/databases/1/items/1034.wav HTTP/1.1

    2007-11-05 14:17:53 (b49e8e26): Session 0: Streaming file '1_1.2_14. Aerodynamic.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:19:21 (b49e8e26): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:19:21 (defa623c): Request: GET daap://146.244.184.248:9999/databases/1/items/1061.wav HTTP/1.1

    2007-11-05 14:19:21 (defa623c): Session 0: Streaming file '1_1.5_10. Make Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:19:22 (defa623c): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:19:22 (b49f1a87): Request: GET daap://146.244.184.248:9999/databases/1/items/1061.wav HTTP/1.1

    2007-11-05 14:19:22 (b49f1a87): Session 0: Streaming file '1_1.5_10. Make Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:24:19 (defaee9d): Request: GET daap://146.244.184.248:9999/databases/1/items/1062.wav HTTP/1.1

    2007-11-05 14:24:19 (defaee9d): Session 0: Streaming file '1_1.6_10. The Brainwasher.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:24:50 (b0ae96e3): Rescanning database
    2007-11-05 14:24:56 (b0ae96e3): Starting playlist scan
    2007-11-05 14:24:56 (b0ae96e3): Updating playlists
    2007-11-05 14:24:56 (b0ae96e3): Scanned 4249 songs (was 4249) in 6 seconds
    2007-11-05 14:25:29 (defaee9d): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:25:29 (b49fa6e8): Request: GET daap://146.244.184.248:9999/databases/1/items/1059.wav HTTP/1.1

    2007-11-05 14:25:29 (b49fa6e8): Session 0: Streaming file '1_1.3_10. Robot Rock.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:25:30 (b49fa6e8): Error writing to client socket: An established connection was aborted by the software in your host machine.
    2007-11-05 14:25:30 (defb7afe): Request: GET daap://146.244.184.248:9999/databases/1/items/1059.wav HTTP/1.1

    2007-11-05 14:25:30 (defb7afe): Session 0: Streaming file '1_1.3_10. Robot Rock.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:30:15 (defc075f): Request: GET daap://146.244.184.248:9999/databases/1/items/1060.wav HTTP/1.1

    2007-11-05 14:30:15 (defc075f): Session 0: Streaming file '1_1.4_10. Steam Machine.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:35:35 (defc93c0): Request: GET daap://146.244.184.248:9999/databases/1/items/1061.wav HTTP/1.1

    2007-11-05 14:35:35 (defc93c0): Session 0: Streaming file '1_1.5_10. Make Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:38:59 (defc93c0): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:38:59 (defd2021): Request: GET daap://146.244.184.248:9999/databases/1/items/1033.wav HTTP/1.1

    2007-11-05 14:38:59 (defd2021): Session 0: Streaming file '1_1.1_14. One More Time.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:38:59 (defd2021): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:38:59 (defdac82): Request: GET daap://146.244.184.248:9999/databases/1/items/1033.wav HTTP/1.1

    2007-11-05 14:38:59 (defdac82): Session 0: Streaming file '1_1.1_14. One More Time.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:44:18 (defe38e3): Request: GET daap://146.244.184.248:9999/databases/1/items/1034.wav HTTP/1.1

    2007-11-05 14:44:18 (defe38e3): Session 0: Streaming file '1_1.2_14. Aerodynamic.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:47:47 (defec544): Request: GET daap://146.244.184.248:9999/databases/1/items/1035.wav HTTP/1.1

    2007-11-05 14:47:47 (defec544): Session 0: Streaming file '1_1.3_14. Digital Love.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:52:44 (deff51a5): Request: GET daap://146.244.184.248:9999/databases/1/items/1036.wav HTTP/1.1

    2007-11-05 14:52:44 (deff51a5): Session 0: Streaming file '1_1.4_14. Harder, Better, Faster, Stronger.flac' to 146.244.184.19 (offset 0)
    2007-11-05 14:53:40 (deff51a5): Error writing to client socket: An existing connection was forcibly closed by the remote host.
    2007-11-05 14:53:40 (e942016d): Thread 176: could not read: unknown internal error
    2007-11-05 15:24:58 (b0ae96e3): Rescanning database
    2007-11-05 15:25:04 (b0ae96e3): Starting playlist scan
    2007-11-05 15:25:04 (b0ae96e3): Updating playlists
    2007-11-05 15:25:04 (b0ae96e3): Scanned 4249 songs (was 4249) in 6 seconds
    2007-11-05 16:16:14 (e9428dce): Request: GET daap://146.244.184.248:9999/databases/1/items/443.wav HTTP/1.1

    2007-11-05 16:16:14 (e9428dce): Session 0: Streaming file '1_1.5_12. Drown Me Slowly.flac' to 146.244.184.26 (offset 0)
    2007-11-05 16:17:20 (e9428dce): Error writing to client socket: An established connection was aborted by the software in your host machine.
    2007-11-05 16:17:28 (deffde06): Thread 193: could not read: Unknown error
    2007-11-05 16:18:16 (b4a03349): Thread 185: could not read: unknown internal error

    A file leecher like mytunes pulling down flacs as fast as possible will definitely peg your cpu.

    That’s likely your culprit.

    — Ron

    #14199
    Anonymous
    Inactive

    @rpedde wrote:

    A file leecher like mytunes pulling down flacs as fast as possible will definitely peg your cpu.

    That’s likely your culprit.

    — Ron

    The thing is, it stays at 100% long after anyone has finished whatever they were doing. Like right now- firefly.exe is running at 100% CPU, but the last person to try and listen to a song was three hours ago.

    I wish it were possible to block mytunes and what not on here, but unfortunately due to network constraints that just isn’t possible 🙁

    #14200
    dantidote
    Participant

    I have zero files that must be transcoded, but it’ll still hover at 100%. Even when no one is connected. Weird.

    #14201
    rpedde
    Participant

    @dantidote wrote:

    I have zero files that must be transcoded, but it’ll still hover at 100%. Even when no one is connected. Weird.

    Just as a data point, do either of you see high cpu if you disable background scanning by setting the scan_interval to 0?

    #14202
    Anonymous
    Inactive

    I turned off scanning completely and it’s still sitting there using 100%- the last activity was an hour ago.

    #14203
    rpedde
    Participant

    @redbeard wrote:

    I turned off scanning completely and it’s still sitting there using 100%- the last activity was an hour ago.

    Okay, good. I appreciate the help. I’m going to finish up working on playlists, and once I’ve finished that, I’ll try and nail this down.

    — Ron

    #14204
    Anonymous
    Inactive

    I am having this pegged CPU utilization issue as well.

    I am running:
    2007-11-14 10:19:18 (3c77e18b): Firefly Version svn-1696: Starting with debuglevel 2
    2007-11-14 10:19:19 (3c77e18b): Plugin loaded: w32-event/svn-1696
    2007-11-14 10:19:19 (3c77e18b): Plugin loaded: ssc-wma/svn-1696
    2007-11-14 10:19:19 (3c77e18b): Plugin loaded: ssc-ffmpeg/svn-1696
    2007-11-14 10:19:19 (3c77e18b): Plugin loaded: rsp/svn-1696
    2007-11-14 10:19:19 (3c77e18b): Plugin loaded: daap/svn-1696
    2007-11-14 10:19:19 (3c77e18b): Starting rendezvous daemon
    2007-11-14 10:19:19 (3c77e18b): Building drive mapping table from C:Program FilesFirefly Media Servermapping.ini
    2007-11-14 10:19:19 (3c77e18b): Initializing database
    2007-11-14 10:19:28 (3c77e18b): Starting web server from C:Program FilesFirefly Media Serveradmin-root on port 9999
    2007-11-14 10:19:28 (3c77e18b): Registering rendezvous names
    2007-11-14 10:19:28 (3c77e18b): Serving 12514 songs. Startup complete in 10 seconds.

    Running on Windoze XP Pro with SP2, AMD 1.4 GHZ, and 1.2GB RAM.

    I have scanning disabled and no one is accessing the server as this is on my home private network.

    I start the server up with no clients hitting it, come back in a few hours and the server is at 100%. Memory utilization is only at about 8,000k on firefly.exe and 5,168k on FireflyShell.exe

    Update: My server was running for 23 hours at 1-2% CPU utilization. On the 23rd hour, firefly.exe flatlined at 95% utilization. I have logging set to the highest level and no new events are recorded from the log events seen above.

    About two hours ago a connected two clients to the server, an itunes client and a Banshee client. Both clients connected to the server, loaded up the playlist and then I closed down the clients.

Viewing 15 posts - 1 through 15 (of 22 total)
  • The forum ‘Nightlies Feedback’ is closed to new topics and replies.