<<<excessive RSS and load>>> Terminator problem (28.160.7328/7328/7328/1.8.0_181-8u181-b13-2~deb9u1-b13/Linux 4.9.0-8-amd64/amd64 x12)

[Guenther Thomsen]

After serving me faithfully for several days, the terminator session just slowed to a crawl and eats a lot of CPU and memory:
--8<--
top - 17:08:23 up 26 days,  6:28,  4 users,  load average: 12.18, 12.14, 11.24
Tasks: 372 total,   2 running, 351 sleeping,  17 stopped,   2 zombie
%Cpu(s): 83.3 us,  7.3 sy,  0.0 ni,  9.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32916404 total, 17150764 free, 13435184 used,  2330456 buff/cache
KiB Swap: 31250428 total, 28118896 free,  3131532 used. 17169976 avail Mem 

   30 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/3:0H                                                                                
 1097 guthoms+  20   0 12.328g 5.569g  21108 S 947.2 17.7 568:45.33 java                                                                                        
 7728 guthoms+  20   0   13392   2176   2120 R  99.4  0.0  19:41.43 telnet             
-->8--

with
--8<--
$ ps -fp 1097
UID        PID  PPID  C STIME TTY          TIME CMD
guthoms+  1097  1070  1 Jan23 pts/3    09:57:43 java -Dorg.jessies.libraryDirectories=/usr/share/software.jessies.org/terminator/Resources/salma-hayek/.generate
-->8--

There was *a lot* of output in that session over the last few days and seemingly that's held in memory. I figure at ~12GiB, the JVM decided enough is enough and attempts a full GC, which utilizes the CPU quite a bit and is slow, as some of the memory has been swapped out (to spinning rust in this case) already.

It appears that keeping the history in memory is not suited for long lasting terminal sessions with lots of output. It would be nice, if the tool could offer a 'pruning' option, allowing the user to get rid of old data.

cheers
~ Guenther

[Martin Dorey]

It does, generally bound to alt-k, clear scroll back or some such but it should do that automatically when memory gets tight.

--
You received this message because you are subscribed to the Google Groups "terminator-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to terminator-use...@googlegroups.com.
To post to this group, send email to terminat...@googlegroups.com.
Visit this group at https://groups.google.com/group/terminator-users.
For more options, visit https://groups.google.com/d/optout.

[Martin Dorey]

I looked at it on Guenther's desktop.  In the example I set up, he had plenty of RAM to accommodate the 36 million lines of output from yes(1), but the UI became unusable.  CPU was at ~1000%, even after I'd done killall yes in another window.  Because it had plenty of memory, it didn't know to automatically flush the scroll back.  When I manually did it, responsiveness came back.  I didn't see any really convincing stuck threads.  If we're doing something O(n*n), which is what it felt like, then I'd have expected to see something there.  Still, I bet it's an effective regression with Elliott's change to remove -Xmx in 

https://github.com/software-jessies-org/jessies/commit/bb72e9f45da43c47808123f251101d156981cbeb.

[Elliott Hughes]

Oops. 

I guess we should put the -Xmx back, make it clearer that it's setting the *max* (not "default") and add a better motivating comment? 

(I can do it this weekend, but if you have time before then...)

[Martin Dorey]

It seems that +Guenther hasn't been getting the replies.  Before making any changes, I'd like a reproducible test case.  Increasing the number of lines by ten million at a time, things felt clunky but kinda linear up to and including:

martind@swiftboat:~$ DEBUGGING_TERMINATOR=y time terminator -e bash -c 'yes | head --lines 31001001'

2019-03-07T13:50:15.727-0800 Terminator: Java 1.8.0_171 (VM 25.171-b11, runtime 1.8.0_171-8u171-b11-1~bpo8+1-b11)

2019-03-07T13:50:15.727-0800 Terminator: Linux 3.16.0-7-amd64/amd64 x8

2019-03-07T13:50:15.727-0800 Terminator: Package 28.186.7354

2019-03-07T13:50:15.728-0800 Terminator: Revision 7354 (7354)

2019-03-07T13:50:15.728-0800 Terminator: Built 2019-03-04T11:34:11-08:00

...

305.26user 21.15system 1:16.72elapsed 425%CPU (0avgtext+0avgdata 6419112maxresident)k

0inputs+181912outputs (0major+1722012minor)pagefaults 0swaps

martind@swiftboat:~$ 

So 77s elapsed.  This following one was the first run where things went off a cliff:

martind@swiftboat:~$ DEBUGGING_TERMINATOR=y time terminator -e bash -c 'yes | head --lines 41001001'

2019-03-07T13:51:45.868-0800 Terminator: Java 1.8.0_171 (VM 25.171-b11, runtime 1.8.0_171-8u171-b11-1~bpo8+1-b11)

...

2019-03-07T13:59:06.428-0800 Terminator: waitFor returned on PtyProcess[pid=11071,fd=-1,pty="/dev/pts/3",didExitNormally,exitValue=0]

...

2019-03-07T14:01:47.654-0800 Terminator: (hang #10) event dispatch thread unstuck after 8.34s.

4318.55user 29.91system 10:04.23elapsed 719%CPU (0avgtext+0avgdata 7431280maxresident)k

96inputs+241424outputs (1major+2177649minor)pagefaults 0swaps

martind@swiftboat:~$ 

I can still type happily in this browser, but every core was maxed out for, well, ten minutes.  The competition took a twentieth of the time and only used maybe 1.5 cores (including for head):

martind@swiftboat:~$ /usr/lib/gnome-terminal/gnome-terminal-server --app-id my.first.Terminal & sleep 0.5; gnome-terminal --app-id my.first.Terminal -x bash -c 'yes | head --lines 41001001'; time fg

[2] 14586

/usr/lib/gnome-terminal/gnome-terminal-server --app-id my.first.Terminal

real 0m28.677s

user 0m17.760s

sys 0m19.200s

martind@swiftboat:~$ 

If I apply a minimal reinstatement of the previous limit:

martind@swiftboat:~/jessies/work/salma-hayek/bin$ git diff

diff --git a/salma-hayek/bin/invoke-java.rb b/salma-hayek/bin/invoke-java.rb

index 43fc2c4..0d48335 100755

--- a/salma-hayek/bin/invoke-java.rb

+++ b/salma-hayek/bin/invoke-java.rb

@@ -389,6 +389,8 @@ class Java

     

     add_property("e.util.Log.applicationName", @app_name)

 

+    args << "-Xmx1g"

+

     if target_os() == "Darwin"

       args << "-Xdock:name=#{@app_name}"

       args << "-Xdock:icon=#{@mac_dock_icon}"

... then the test case completes five times faster and without grinding the entire 8 core, 32 GiB RAM machine into the ground.  I notice the automatic flusher kicking off, which didn't happen before:

martind@swiftboat:~$ DEBUGGING_TERMINATOR=y time terminator -e bash -c 'yes | head --lines 41001001'

2019-03-07T14:38:19.123-0800 Terminator: Java 1.8.0_171 (VM 25.171-b11, runtime 1.8.0_171-8u171-b11-1~bpo8+1-b11)

...

2019-03-07T14:38:41.681-0800 Terminator: Available memory down to 216639112, flushing biggest scroll buffer...

...

2019-03-07T14:38:59.525-0800 Terminator: Available memory down to 215221952, flushing biggest scroll buffer...

...

2019-03-07T14:39:23.42-0800 Terminator: Available memory down to 213226776, flushing biggest scroll buffer...

...

2019-03-07T14:39:47.217-0800 Terminator: Available memory down to 213220744, flushing biggest scroll buffer...

...

2019-03-07T14:40:04.390-0800 Terminator: Available memory down to 211498800, flushing biggest scroll buffer...

...

2019-03-07T14:40:25.877-0800 Terminator: Available memory down to 196582736, flushing biggest scroll buffer...

...

736.83user 24.92system 2:12.81elapsed 573%CPU (0avgtext+0avgdata 1247668maxresident)k

504inputs+240576outputs (13major+414108minor)pagefaults 0swaps

martind@swiftboat:~$ 

Generating continuous output seems like a perfectly reasonable use-case to me, one which I had thought we'd made work with the previous round of "flushing biggest scroll buffer" changes in the Yogesh Gangurde era.  I pushed it, with a small code-comment.