4.0.3 has huge memory and CPU footprint in High Sierra

General discussions about Little Snitch
christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Tue Jun 05, 2018 9:28 am

The objects we know of account for a couple of megabytes. That's definitely a few orders of magnitude less than the amount of memory reported by Activity Monitor.

Can you please open Activity Monitor to find out the Process ID (PID) of Network Monitor and then open a Terminal window and typ

vmmap PID_OF_NETWORK_MONITOR

(replacing PID_OF_NETWORK_MONITOR with the actual PID, of course). Please either paste the output of the command here as code snippet or mail it to us in support. It lists all memory sections currently assigned to the process and the library which allocated them.

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Thu Jun 07, 2018 8:36 pm

Can you please [...]


Sorry, I only just noticed this response, and have recently rebooted my machine, so LSNM is currently being very well-behaved, consuming only 88mb of memory (as reported by Activity Monitor).

I will wait until the next time symptoms appear; I predict this will be overnight tonight, so I'll probably post results tomorrow morning.

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Sat Jun 09, 2018 10:19 am

LSNM is only up to about 1GB right now, but here's the current output of vmmap: https://pastebin.com/BxBW2XiG

... and another look at the console log at about the same time:

Code: Select all

2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741] #### object allocation statistics: ####
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]             LSMDataModel:        1 208 bytes each
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]         LSMConnectionSet:        9 88 bytes each
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]     LSMSummaryConnection:    32282 240 bytes each
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]        LSMTrafficHistory:      455 1976 bytes each
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]          LSMProcessGroup:      249
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741] ----- Connections in Live Set: -----
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]      Logical Connections:    20002
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741] Peer Summary Connections:    11356
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]  Dom Summary Connections:      643
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]  App Summary Connections:      124
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741] ----- Other: -----
2018-06-09 01:13:23.726 Little Snitch Network Monitor[524:4741]    LSMPhysicalConnection:    11392 (0 null, 0 inactive)
2018-06-09 01:13:23.727 Little Snitch Network Monitor[524:4741] LSMTrafficHistory (live):      455
2018-06-09 01:13:23.727 Little Snitch Network Monitor[524:4741]         2.62 MB bytes for objects
2018-06-09 01:13:23.727 Little Snitch Network Monitor[524:4741]         1.72 MB in 7161 32-bit sections
2018-06-09 01:13:23.727 Little Snitch Network Monitor[524:4741]         0 B in 0 64-bit sections
2018-06-09 01:13:23.727 Little Snitch Network Monitor[524:4741] #### end statistics ####

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Sat Jun 09, 2018 12:03 pm

Unfortunately, the diagnostics is not too informative. I can see that most of the memory (more than 800 MB) is allocated in one chunk. The chunk is from VM_ALLOCATE. This can be pretty much anything. Assuming that the memory is assigned in sequential order (which is somewhat reasonable), we can draw conclusions from the surrounding allocations:

Code: Select all

CoreAnimation          00000001190a1000-000000011919f000 [ 1016K     0K     0K   312K] rw-/rwx SM=SHM PURGE=N 
VM_ALLOCATE            000000011919f000-000000011957a000 [ 3948K  3948K  3948K     0K] rw-/rwx SM=PRV         
mapped file            000000011957a000-000000011992a000 [ 3776K  2896K     0K     0K] rw-/rwx SM=COW          ...ar/folders/th/zlkp5nsd0zx9hjt16_n8bpcr0000gn/0/com.apple.LaunchServices-221-v2.csstore
VM_ALLOCATE            000000011992a000-000000014cf15000 [821.9M 821.9M 821.9M     8K] rw-/rwx SM=PRV         
CoreAnimation          000000014cf15000-000000014cf1e000 [   36K    36K    36K     0K] rw-/rwx SM=SHM PURGE=V 
CoreAnimation          000000014cf1e000-000000014cf42000 [  144K   144K   144K     0K] rw-/rwx SM=SHM PURGE=N 


That would point to CoreAnimation. I have no idea why CoreAnimation should map a LaunchServices file, though, which is right before the big chunk. Would be interesting to see what data is inside the chunk, but we protect Little Snitch against debugger attachment, so we have no chance here...

This is just one incident. Things might be arranged differently the next time. Can you try this a second time? If it's the same, we must think about a mechanism to look deeper. If we get more info, there might be other ways...

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Sat Jun 09, 2018 10:36 pm

Can you try this a second time?


Which would be more helpful? Kill LSNM and let it grow again from scratch, or leave it alone to see if it grows even larger?

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Sat Jun 09, 2018 11:36 pm

Don't know. Maybe let it grow even further and then compare the memory maps to see what was added.

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Wed Jun 13, 2018 5:14 am

The process has grown to 1.86GB: https://pastebin.com/ekQZkB0C

Console logs:

Code: Select all

2018-06-12 20:14:16.641 Little Snitch Network Monitor[524:4741] #### object allocation statistics: ####
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]             LSMDataModel:        1 208 bytes each
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]         LSMConnectionSet:        1 88 bytes each
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]     LSMSummaryConnection:    32187 240 bytes each
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]        LSMTrafficHistory:      648 1976 bytes each
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]          LSMProcessGroup:      254
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741] ----- Connections in Live Set: -----
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]      Logical Connections:    19999
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741] Peer Summary Connections:    11329
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]  Dom Summary Connections:      572
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]  App Summary Connections:      126
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741] ----- Other: -----
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741]    LSMPhysicalConnection:    30928 (0 null, 0 inactive)
2018-06-12 20:14:16.642 Little Snitch Network Monitor[524:4741] LSMTrafficHistory (live):      648
2018-06-12 20:14:16.643 Little Snitch Network Monitor[524:4741]         3.06 MB bytes for objects
2018-06-12 20:14:16.643 Little Snitch Network Monitor[524:4741]         1.78 MB in 7404 32-bit sections
2018-06-12 20:14:16.643 Little Snitch Network Monitor[524:4741]         0 B in 0 64-bit sections
2018-06-12 20:14:16.643 Little Snitch Network Monitor[524:4741] #### end statistics ####


This is the same process that's been running since my previous vmmap results.

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Wed Jun 13, 2018 10:33 am

Thanks a lot for the new vm statistics!

I can see that the old block of 822M from last time is still allocated, but it moved a bit and has grown by ca. 1 MB. It's now allocated side-by-side with CG image blocks, so it must have been allocated by something which creates Core Graphics Images.

The large block as well as the images have not been touched for a long time, they have all been swapped to disk. I therefore conclude that it's lost (leaked) memory.

Then there's a new large block of 629.4M, directly preceded by a CoreAnimation block. It's not (yet) swapped to disk, so its more recent. Again, we have the relation to Core Animation and probably Core Graphics.

I think that these blocks are backing stores for table cells. Cells of the connection list. That's one of the points where Core Animation is used for animating cells moving around. If a large block of cells moves, the table view probably makes an image for the entire block and lets the graphics card animate it.

One question is why the image can leak, and the second what we can do to prevent or at least mitigate this. We use a high level API to move table rows around. This API has probably been made to animate a small block of rows from one position to an other, e.g. as a consequence of a user interaction. We do lots of animations with it, often overlapping (the next one starts before the first one finished). There are many edge cases when animations overlap and one of them might leak memory.

We'll discuss possible mitigations internally. I'm afraid that we won't have a fix or workaround within short timeframe, though.

For the moment, you can reset memory usage by either killing Network Monitor from Activity Monitor or turning it off in Little Snitch Configuration's preferences and turning it on again.

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Wed Jun 13, 2018 10:38 am

Sorry to correct myself: I just wanted to write down what we've found out. And I found a very similar bug description there. Network Monitor does not deallocate snapshot windows. If you make a snapshot of a window (or probably also if you load one), the window (and its memory) is not freed when you close it.

Is it possible that the large chunks of memory are related to snapshots?

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Wed Jun 13, 2018 11:04 pm

Thanks for the detailed update!

This execution of LSNM hasn't yet grown to a burdensome level, so I'm going to leave it running and post new vm stats when and if it grows again. (Unless you're sure you have all you need, in which case I won't bother.)

Network Monitor does not deallocate snapshot windows. If you make a snapshot of a window (or probably also if you load one), the window (and its memory) is not freed when you close it.

Is it possible that the large chunks of memory are related to snapshots?


Forgive my ignorance: in this context, are "snapshots" a Little Snitch user-level feature I might be triggering, or something going on under the hood?

Is there something I could try doing (or not doing) that might make a difference?

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Thu Jun 14, 2018 9:39 am

You make a snapshot of the current connections window by hitting Cmd-D or by choosing File > Make Snapshot from the menu. You can save and load snapshots. This feature can be used to analyze something without hurry.

Since you did not know about it, it's probably not the cause. And I have just tried it: The memory leaked this way is hardly noticeable.

One more vm statistics would be nice, just to be sure it does not contradict the theory. There are no hard facts, so we have to guess anyway.

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Sun Jun 17, 2018 2:10 am

That LSNM process just "quit unexpectedly" (I had not noticed it grow again since my previous update), and LS now wants to install 4.1, so that's all the data I have for 4.0.6.

I'll report back when/if I see similar symptoms in 4.1

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Sun Jun 17, 2018 8:09 pm

When it "quit unexpectedly", it leaves a crash log in ~/Library/Logs. You can view it with Console.app, or it's included (among lots of other info) when you send us a diagnostics report. You can do so by following these steps:

• Open Little Snitch Configuration
• Click “Help” in the menu bar
• Hold the ⌥ (Option) key and choose “Diagnostics Report…”
• Follow the instructions
• This will result in a file on your Desktop. Please send us this file as an email attachment in support:

https://obdev.at/support/?product=LS&topic=contact

durandal42
Rank 1
Rank 1
Posts: 25
Joined: Wed Aug 09, 2017 9:35 pm

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby durandal42 » Sun Jun 17, 2018 10:44 pm

Please send us this file as an email attachment in support


Done!

christian
Objective Development
Objective Development
Posts: 1429
Joined: Thu Nov 09, 2006 11:46 am

Re: 4.0.3 has huge memory and CPU footprint in High Sierra

Postby christian » Sun Jun 17, 2018 11:12 pm

Thanks a lot for the diagnostics report!

As far as I can tell, there must be a problem with your graphics driver. This may not be directly related to your memory issue, but it's impacting responsiveness and performance of your computer.

In the LS Daemon logs, I can see tons of messages like this:

2018-06-17 13:29:44.020 Little Snitch Daemon[90:848] 4.0.6 (5124): m26b16e2b: 47216 5 0
2018-06-17 13:31:49.115 Little Snitch Daemon[90:848] 4.0.6 (5124): m26b16e2b: 47248 5 0
2018-06-17 13:33:54.211 Little Snitch Daemon[90:848] 4.0.6 (5124): m26b16e2b: 47279 5 0
2018-06-17 13:35:59.296 Little Snitch Daemon[90:848] 4.0.6 (5124): m26b16e2b: 47300 5 0
2018-06-17 13:38:04.384 Little Snitch Daemon[90:848] 4.0.6 (5124): m26b16e2b: 47330 5 0

Each of these messages means that one of our components, LS Agent, became unresponsive and we had to restart it. That's every 2 minutes!

Luckily, your diagnostics report also contains spindumps of the hang. One example:

Code: Select all

...
1015  RunCurrentEventLoopInMode + 286 (HIToolbox + 194662) [0x7fff29fa6866]
  1015  CFRunLoopRunSpecific + 487 (CoreFoundation + 530327) [0x7fff2ac91797]
    1015  __CFRunLoopRun + 1240 (CoreFoundation + 532232) [0x7fff2ac91f08]
      1015  __CFRunLoopDoObservers + 511 (CoreFoundation + 652287) [0x7fff2acaf3ff]
        1015  __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__ + 23 (CoreFoundation + 652503) [0x7fff2acaf4d7]
          1015  __65+[CATransaction(NSCATransaction) NS_setFlushesWithDisplayRefresh]_block_invoke + 283 (AppKit + 9664228) [0x7fff28b996e4]
            1015  CA::Transaction::commit() + 487 (QuartzCore + 66037) [0x7fff35d8a1f5]
              1015  CA::Context::commit_transaction(CA::Transaction*) + 3316 (QuartzCore + 70134) [0x7fff35d8b1f6]
                1015  CA::Transaction::run_commit_handlers(CATransactionPhase) + 49 (QuartzCore + 70823) [0x7fff35d8b4a7]
                  1015  __39+[_NSCGSTransaction currentTransaction]_block_invoke + 34 (AppKit + 1528071) [0x7fff283d7107]
                    1015  NSCGSTransactionRunPreCommitActions_ + 31 (AppKit + 1528114) [0x7fff283d7132]
                    ...


It has deadlocked in Core Animation!

This is not a rare issue. In previous releases, we brought up an error dialog when this happened. For some users, it happens all the time (like in your case) and the dialog would be very annoying.

LS Agent is responsible for showing Connection Alerts. If it hangs, alerts are delayed.

The bad news is that we still have not found out how this can happen. When you look at the file LittleSnitchDaemon.log from your diagnostics report, you'll notice that there are days and times where no hangs occur. Is your computer off during these times? Or can you find a pattern, maybe a kind of work you do, a program you run or something else which may cause this behavior?


Return to “Little Snitch General”

Who is online

Users browsing this forum: No registered users and 4 guests

cron