Test Failed
Push — master ( ef441d...0acd10 )
by Heiko 'riot'
04:41 queued 10s
created

isomer.debugger.MemoryLogger.cli_mem_chart()   B

Complexity

Conditions 5

Size

Total Lines 43
Code Lines 29

Duplication

Lines 0
Ratio 0 %

Importance

Changes 0
Metric Value
cc 5
eloc 29
nop 2
dl 0
loc 43
rs 8.7173
c 0
b 0
f 0
1
#!/usr/bin/env python
2
# -*- coding: UTF-8 -*-
3
4
# Isomer - The distributed application framework
5
# ==============================================
6
# Copyright (C) 2011-2020 Heiko 'riot' Weinen <[email protected]> and others.
7
#
8
# This program is free software: you can redistribute it and/or modify
9
# it under the terms of the GNU Affero General Public License as published by
10
# the Free Software Foundation, either version 3 of the License, or
11
# (at your option) any later version.
12
#
13
# This program is distributed in the hope that it will be useful,
14
# but WITHOUT ANY WARRANTY; without even the implied warranty of
15
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
16
# GNU Affero General Public License for more details.
17
#
18
# You should have received a copy of the GNU Affero General Public License
19
# along with this program.  If not, see <http://www.gnu.org/licenses/>.
20
21
"""
22
23
24
Module: Debugger
25
================
26
27
Debugger overlord
28
29
30
"""
31
32
import json
33
from collections import deque
34
from itertools import islice
35
from uuid import uuid4
36
37
import asciichartpy
38
from circuits.core import Timer
39
from circuits.core.events import Event
40
from circuits.core.handlers import reprhandler
41
from circuits.io import stdin
42
from isomer.logger import isolog, critical, error, warn, debug, verbose, verbosity
43
from isomer.component import ConfigurableComponent, handler
44
from isomer.events.client import send
45
from isomer.events.system import (
46
    frontendbuildrequest,
47
    componentupdaterequest,
48
    logtailrequest,
49
)
50
51
try:
52
    # noinspection PyPackageRequirements
53
    import objgraph
54
except ImportError:
55
    objgraph = None
56
57
try:
58
    # noinspection PyPackageRequirements
59
    from guppy import hpy
60
except ImportError:
61
    hpy = None
62
63
try:
64
    # noinspection PyPackageRequirements
65
    from pympler import tracker, muppy, summary
66
except ImportError:
67
    tracker = None
68
    muppy = None
69
    summary = None
70
71
72
class clicommand(Event):
73
    """Event to execute previously registered CLI event hooks"""
74
75
    def __init__(self, cmd, cmdargs, *args, **kwargs):
76
        super(clicommand, self).__init__(*args, **kwargs)
77
        self.cmd = cmd
78
        self.args = cmdargs
79
80
81
class cli_register_event(Event):
82
    """Event to register new command line interface event hooks"""
83
84
    def __init__(self, cmd, thing, *args, **kwargs):
85
        super(cli_register_event, self).__init__(*args, **kwargs)
86
        self.cmd = cmd
87
        self.thing = thing
88
89
90
class cli_help(Event):
91
    """Display this command reference
92
93
    Additional arguments:
94
        -v      Add detailed information about hook events in list
95
96
        command Show complete documentation of a hook command
97
    """
98
99
    pass
100
101
102
class cli_errors(Event):
103
    """Display errors in the live log"""
104
105
    pass
106
107
108
class cli_locations(Event):
109
    """Display all locations of running instance"""
110
111
    pass
112
113
114
class cli_log_level(Event):
115
    """Adjust log level
116
117
    Argument:
118
        [int]   New logging level (0-100)
119
    """
120
121
    pass
122
123
124
class cli_comp_graph(Event):
125
    """Draw current component graph"""
126
127
    pass
128
129
130
class cli_mem_summary(Event):
131
    """Output memory usage summary"""
132
133
    pass
134
135
136
class cli_mem_diff(Event):
137
    """Output difference in memory usage since last call"""
138
139
    pass
140
141
142
class cli_mem_hogs(Event):
143
    """Output most memory intense objects"""
144
145
    pass
146
147
148
class cli_mem_growth(Event):
149
    """Output data about memory growth"""
150
151
    pass
152
153
154
class cli_mem_heap(Event):
155
    """Output memory heap data"""
156
157
    pass
158
159
160
class cli_mem_chart(Event):
161
    """Output memory consumption chart
162
163
    Arguments:
164
        count   Integer specifying the number of last measurements to chart
165
166
    Additional options:
167
        -o      Omit first value
168
    """
169
170
    pass
171
172
173
class cli_exception_test(Event):
174
    """Raise test-exception to check exception handling"""
175
176
    pass
177
178
179
class TestException(BaseException):
180
    """Generic exception to test exception monitoring"""
181
182
    pass
183
184
185
class IsomerDebugger(ConfigurableComponent):
186
    """
187
    Handles various debug requests.
188
    """
189
190
    configprops = {
191
        "notificationusers": {
192
            "type": "array",
193
            "title": "Notification receivers",
194
            "description": "Users that should be notified about exceptions.",
195
            "default": [],
196
            "items": {"type": "string"},
197
        }
198
    }
199
    channel = "isomer-web"
200
201
    def __init__(self, root=None, *args):
202
        super(IsomerDebugger, self).__init__("DBG", *args)
203
204
        if not root:
205
            from isomer.logger import root
206
207
            self.root = root
208
        else:
209
            self.root = root
210
211
        if objgraph is None:
212
            self.log("Cannot use objgraph.", lvl=warn)
213
214
        try:
215
            self.fireEvent(cli_register_event("errors", cli_errors))
216
            self.fireEvent(cli_register_event("log_level", cli_log_level))
217
            self.fireEvent(cli_register_event("comp_graph", cli_comp_graph))
218
            self.fireEvent(cli_register_event("locations", cli_locations))
219
            self.fireEvent(cli_register_event("test_exception", cli_exception_test))
220
        except AttributeError:
221
            pass  # We're running in a test environment and root is not yet running
222
223
        try:
224
            self.tracker = tracker.SummaryTracker()
225
        except AttributeError:
226
            self.log("No pympler library for memory analysis installed.", lvl=warn)
227
228
        self.log("Started. Notification users: ", self.config.notificationusers)
229
230
    def _drawgraph(self):
231
        objgraph.show_backrefs(
232
            [self.root],
233
            max_depth=5,
234
            filter=lambda x: type(x) not in [list, tuple, set],
235
            highlight=lambda x: type(x) in [ConfigurableComponent],
236
            filename="backref-graph.png",
237
        )
238
        self.log("Backref graph written.", lvl=critical)
239
240
    @handler("cli_errors")
241
    def cli_errors(self, *args):
242
        """Display errors in the live log"""
243
244
        self.log("All errors since startup:")
245
        from isomer.logger import LiveLog
246
247
        for logline in LiveLog:
248
            if logline[1] >= error:
249
                self.log(logline, pretty=True)
250
251
    @handler("cli_log_level")
252
    def cli_log_level(self, *args):
253
        """Adjust log level"""
254
255
        new_level = int(args[0])
256
        self.log("Adjusting logging level to", new_level)
257
258
        verbosity["global"] = new_level
259
        verbosity["console"] = new_level
260
        verbosity["file"] = new_level
261
262
    @handler("cli_compgraph")
263
    def cli_compgraph(self, event):
264
        """Draw current component graph"""
265
266
        self.log("Drawing component graph")
267
        from circuits.tools import graph
268
269
        graph(self)
270
        self._drawgraph()
271
272
    @handler("cli_locations")
273
    def cli_locations(self, *args):
274
        """Display all locations of running instance"""
275
276
        self.log("All locations for this instance:")
277
        from isomer.misc.path import locations, get_path
278
279
        for path in locations:
280
            self.log(get_path(path, ""), pretty=True)
281
282
    @handler("cli_exception_test")
283
    def cli_exception_test(self, *args):
284
        """Raise test-exception to check exception handling"""
285
286
        raise TestException
287
288
    @handler("debug_store_json")
289
    def debug_store_json(self, event):
290
        """A debug-endpoint to store an event as json dump"""
291
292
        self.log("Storing received object to /tmp", lvl=critical)
293
        fp = open(
294
            "/tmp/isomer_debugger_" + str(event.user.useruuid) + "_" + str(uuid4()), "w"
295
        )
296
        json.dump(event.data, fp, indent=True)
297
        fp.close()
298
299
    @handler(logtailrequest)
300
    def logtailrequest(self, event):
301
        self.log("Log requested")
302
303
    @handler("exception", channel="*", priority=1.0)
304
    def _on_exception(self, error_type, value, traceback, handler=None, fevent=None):
305
        # TODO: Generate hashes and thus unique urls with exceptions and fill
306
        #  them out with this data:
307
        #  self.log('EXCEPTIONHANDLER:', error_type, value, traceback, lvl=critical)
308
        #  The idea is to have error pages in the documentation/public Isomer instance
309
        #  so people can discuss and get help on runtime errors, like with the
310
        #  exitcodes system in the documentation
311
312
        try:
313
            s = []
314
315
            if handler is None:
316
                handler = ""
317
            else:
318
                handler = reprhandler(handler)
319
320
            msg = "ERROR"
321
            msg += "{0:s} ({1:s}) ({2:s}): {3:s}\n".format(
322
                handler, repr(fevent), repr(error_type), repr(value)
323
            )
324
325
            s.append(msg)
326
            s.append("\n")
327
328
            isolog("\n".join(s), "\n".join(traceback),
329
                   lvl=critical, frame_ref=3, emitter="DEBUG")
330
331
            alert = {
332
                "component": "isomer.alert.manager",
333
                "action": "notify",
334
                "data": {
335
                    "type": "danger",
336
                    "message": "\n".join(s),
337
                    "title": "Exception Monitor",
338
                },
339
            }
340
            for user in self.config.notificationusers:
341
                self.fireEvent(send(None, alert, username=user, sendtype="user"))
342
343
        except Exception as e:
344
            self.log("Exception during exception handling: ", e, type(e), lvl=critical,
345
                     exc=True)
346
347
348
class CLI(ConfigurableComponent):
349
    """
350
    Command Line Interface support
351
352
    This is disabled by default.
353
    To enable the command line interface, use either the Configuration frontend,
354
    or the iso tool:
355
356
    .. code-block:: sh
357
358
        iso config enable CLI
359
360
    """
361
362
    configprops = {}
363
364
    def __init__(self, *args):
365
        super(CLI, self).__init__("CLI", *args)
366
367
        self.hooks = {}
368
369
        self.log("Started")
370
        stdin.register(self)
371
        self.fire(cli_register_event("help", cli_help))
372
373
    @handler("read", channel="stdin")
374
    def stdin_read(self, data):
375
        """read Event (on channel ``stdin``)
376
        This is the event handler for ``read`` events specifically from the
377
        ``stdin`` channel. This is triggered each time stdin has data that
378
        it has read.
379
        """
380
381
        data = data.strip().decode("utf-8")
382
        self.log("Incoming:", data, lvl=verbose)
383
384
        def show_error():
385
            self.log(
386
                "Unknown Command: '%s'. Use /help to get a list of enabled "
387
                "cli hooks" % data,
388
                lvl=warn,
389
            )
390
391
        if len(data) == 0:
392
            self.log("Use /help to get a list of enabled cli hooks")
393
            return
394
395
        if data[0] == "/":
396
            cmd = data[1:]
397
            args = []
398
            if " " in cmd:
399
                cmd, args = cmd.split(" ", maxsplit=1)
400
                args = args.split(" ")
401
            if cmd in self.hooks:
402
                self.log("Firing hooked event:", cmd, args, lvl=debug)
403
                self.fireEvent(self.hooks[cmd](*args))
404
            # TODO: Move these out, so we get a simple logic here
405
            elif cmd == "frontend":
406
                self.log(
407
                    "Sending %s frontend rebuild event"
408
                    % ("(forced)" if "force" in args else "")
409
                )
410
                self.fireEvent(
411
                    frontendbuildrequest(
412
                        force="force" in args, install="install" in args
413
                    ),
414
                    "setup",
415
                )
416
            elif cmd == "backend":
417
                self.log("Sending backend reload event")
418
                self.fireEvent(componentupdaterequest(force=False), "setup")
419
            else:
420
                show_error()
421
        else:
422
            show_error()
423
424
    @handler("cli_help")
425
    def cli_help(self, *args):
426
        """Print a list, and a short documentation of all CLI commands"""
427
428
        if len(args) == 0 or args[0].startswith("-"):
429
            self.log("Registered CLI hooks:")
430
            # TODO: Use std_table for a pretty table
431
            command_length = 5
432
            object_length = 5
433
            for hook in self.hooks:
434
                command_length = max(len(hook), command_length)
435
                object_length = max(len(str(self.hooks[hook])), object_length)
436
437
            if "-v" not in args:
438
                object_length = 0
439
440
            for hook in sorted(self.hooks):
441
                self.log(
442
                    "/%s %s: %s"
443
                    % (
444
                        hook.ljust(command_length),
445
                        (
446
                            " - " + str(self.hooks[hook]) if object_length != 0 else ""
447
                        ).ljust(object_length),
448
                        str(self.hooks[hook].__doc__).split("\n", 1)[0],
449
                    )
450
                )
451
        else:
452
            self.log("Help for command", args[0], ":")
453
            self.log(self.hooks[args[0]].__doc__)
454
455
    @handler("cli_register_event")
456
    def register_event(self, event):
457
        """Registers a new command line interface event hook as command"""
458
459
        self.log(
460
            "Registering event hook:", event.cmd, event.thing, pretty=True, lvl=verbose
461
        )
462
        self.hooks[event.cmd] = event.thing
463
464
465
class MemoryLogger(ConfigurableComponent):
466
    """
467
    Periodically logs memory consumption statistics
468
    """
469
470
    configprops = {
471
        "notificationusers": {
472
            "type": "array",
473
            "title": "Notification receivers",
474
            "description": "Users that should be notified about exceptions.",
475
            "default": [],
476
            "items": {
477
                "oneOf": [
478
                    {"type": "string"},
479
                    {"type": "null"}
480
                ]
481
            },
482
        },
483
        "interval": {
484
            "type": "integer",
485
            "title": "Interval",
486
            "description": "Memory growth snapshot interval",
487
            "default": 600,
488
        },
489
        "snapshot_diffs": {
490
            "type": "integer",
491
            "title": "History length (snapshots)",
492
            "description": "Number of memory snapshots diffs to keep",
493
            "default": 30
494
        },
495
        "size_diffs": {
496
            "type": "integer",
497
            "title": "History length (size)",
498
            "description": "Number of memory size diffs to keep",
499
            "default": 1000
500
        }
501
    }
502
    channel = "isomer-web"
503
504
    def __init__(self, *args):
505
        super(MemoryLogger, self).__init__("MEM", *args)
506
507
        if self.args['debug'] is True:
508
            self.log('Debug flag set, decreasing memory logger measurement '
509
                     'interval to 20 seconds')
510
            interval = 20
511
        else:
512
            interval = self.config.interval
513
514
        self.size = 0
515
        self.snapshot_diffs = deque(maxlen=self.config.snapshot_diffs)
516
        self.size_diffs = deque(maxlen=self.config.size_diffs)
517
518
        if hpy is not None:
519
            # noinspection PyCallingNonCallable
520
            self.heapy = hpy()
521
        else:
522
            self.log("Cannot use heapy. guppy package missing?", lvl=warn)
523
524
        if objgraph is None:
525
            self.log("Cannot use objgraph.", lvl=warn)
526
527
        try:
528
            self.fireEvent(cli_register_event("mem_growth", cli_mem_growth))
529
            self.fireEvent(cli_register_event("mem_hogs", cli_mem_hogs))
530
            self.fireEvent(cli_register_event("mem_heap", cli_mem_heap))
531
            self.fireEvent(cli_register_event("mem_summary", cli_mem_summary))
532
            self.fireEvent(cli_register_event("mem_diff", cli_mem_diff))
533
            self.fireEvent(cli_register_event("mem_chart", cli_mem_chart))
534
535
        except AttributeError:
536
            pass  # We're running in a test environment and root is not yet running
537
538
        try:
539
            self.tracker = tracker.SummaryTracker()
540
            self.tracking_timer = Timer(
541
                interval, Event.create("memlog-timer"), persist=True
542
            ).register(self)
543
544
        except AttributeError:
545
            self.tracking_timer = None
546
            self.log("No pympler library for memory analysis installed.", lvl=warn)
547
548
        self.log("Started. Notification users: ", self.config.notificationusers)
549
550
    @handler("memlog-timer")
551
    def memlog_timer(self):
552
553
        growth = 0
554
        diff = self.tracker.diff()
555
556
        for element in diff:
557
            growth += element[2]
558
559
        self.size += growth
560
        self.snapshot_diffs.append(diff)
561
        self.size_diffs.append(growth)
562
563
        log_level = debug
564
        if growth > (self.size * 0.1) and len(self.size_diffs) > 1:
565
            self.log('Memory growth exceeded 10%!', lvl=warn)
566
            log_level = warn
567
        self.log("Memory: total %i growth %i (in %i seconds)" % (
568
            self.size, growth, self.config.interval), lvl=log_level)
569
570
    @handler("cli_mem_summary")
571
    def cli_mem_summary(self, event):
572
        """Output memory usage summary"""
573
574
        all_objects = muppy.get_objects()
575
        state = summary.summarize(all_objects)
576
        summary.print_(state)
577
578
    @handler("cli_mem_diff")
579
    def cli_mem_diff(self, event):
580
        """Output difference in memory usage since last call"""
581
582
        self.tracker.print_diff()
583
584
    @handler("cli_mem_hogs")
585
    def cli_mem_hogs(self, *args):
586
        """Output most memory intense objects"""
587
588
        self.log("Memory hogs:", lvl=critical)
589
        objgraph.show_most_common_types(limit=20)
590
591
    @handler("cli_mem_growth")
592
    def cli_mem_growth(self, *args):
593
        """Output data about memory growth"""
594
595
        self.log("Memory growth since last call:", lvl=critical)
596
        objgraph.show_growth()
597
598
    @handler("cli_mem_heap")
599
    def cli_mem_heap(self, *args):
600
        """Output memory heap data"""
601
602
        self.log("Heap log:", self.heapy.heap(), lvl=critical)
603
604
    @handler("cli_mem_chart")
605
    def cli_mem_chart(self, *args):
606
        """Output memory consumption chart"""
607
608
        config = {
609
            'colors': [
610
                asciichartpy.blue,
611
                asciichartpy.red
612
            ],
613
            'height': 10,
614
            'format': '{:6.0f}kB'
615
        }
616
617
        total_length = len(self.size_diffs)
618
619
        try:
620
            count = int(args[-1])
621
        except (TypeError, ValueError, IndexError):
622
            count = total_length
623
624
        if count > total_length:
625
            self.log('Only %i measurements available!' % total_length, lvl=warn)
626
            return
627
628
        size_k = [x / 1024.0 for x in islice(
629
            self.size_diffs, len(self.size_diffs) - count, len(self.size_diffs)
630
        )]
631
632
        if len(args) > 0:
633
            if "-o" in args:
634
                size_k.pop(0)
635
636
        length = len(size_k)
637
638
        self.log(
639
            "Memory consumption (%i measurements, "
640
            "%i seconds interval, %3.0f minutes total)" % (
641
                length,
642
                self.config.interval,
643
                (length * self.config.interval / 60.0)
644
            )
645
        )
646
        self.log("\n%s" % asciichartpy.plot(size_k, config), nc=True)
647