Memory Leak in sensor-logger

[renereimann]

While #208 and #200 claim to fix the memory leak in sensor-logger, I still experience memory groth in sensor-logger.

The primary memory leak is not related to postgres.
I run tests with a local compilation of dripline-python where I comment out anything in process_payload
(see https://github.com/driplineorg/dripline-python/blob/main/dripline/implementations/postgres_sensor_logger.py#L45).
This still has the same memory leak rate as before.
I run tests with everything commented out in on_alert_message in https://github.com/driplineorg/dripline-python/blob/main/dripline/core/alert_consumer.py#L41.
There still has the same memory leak rate as before.

If I comment out the line with self.bind_key(...) https://github.com/driplineorg/dripline-python/blob/main/dripline/core/alert_consumer.py#L38
The memory leak is fixed, however in this case no alerts are processed at all.

The bind_key function is bound via pybind11 from dripline::_service::pybind
The on_alert_message is bound via dripline::_endpoint:pybind and endpoint and service trampoline and then overwritten in core/alert_consumer.py

[nsoblath]

@renereimann has done some further investigations and found that the issue applies regardless of message type -- the leak was verified for both requests and alerts.

My guess for the most likely places for a problem like this to occur are:

• dl-cpp in the chain where amqp messages are translated into dl messages. There are some unit tests here that ensure some pieces of it are working, but not everything is tested.
• dl-py Python bindings -- perhaps something is getting an extended lifetime that it shouldn't. e.g. if a message from c++ transfers or copies to the Python side and then continues to live.

[nsoblath]

I have some evidence the leak is in dl-cpp. I started simple-service (a C++ service) and used dl-agent to send ping requests. I used a script to send one ping request per second. Then I used top to observe the amount of memory used. The physical memory in use (res) increased by about 8 kB per second.

[nsoblath]

Ok, I think I figured out the source of this error. First of all, here's the memory usage histogram from using valgrind massif on the unfixed code:

--------------------------------------------------------------------------------
Command:            run_simple_service -vv -b rabbit-broker -u dripline --password dripline
Massif arguments:   --stacks=yes --time-unit=ms
ms_print arguments: massif.out.447
--------------------------------------------------------------------------------


    MB
5.600^                                                     #                  
     |                                                     #              :   
     |                                                 @  @#              :   
     |                                @  @ @     @  @  @  @#   :::@:::::@:::::
     |                   @ :     @    @  @ @    :@::@::@::@#::::::@:::::@:::::
     |   :   @    @      @ :   ::@::::@::@:@:::::@::@::@::@#::::::@:::::@:::::
     |   :   @  ::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |  :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |  :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@@:::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
     |@ :::@:@:@::@::::::@:::::: @::::@::@:@: :::@::@::@::@#::::::@:::::@:::::
   0 +----------------------------------------------------------------------->s
     0                                                                   578.9

Number of snapshots: 92
 Detailed snapshots: [1, 6, 8, 11, 14, 21, 28, 33, 36, 39, 44, 47, 51, 56, 59, 60, 61, 62, 63 (peak), 73, 83]

And here's the histogram using the fixed code:

--------------------------------------------------------------------------------
Command:            run_simple_service -vv -b rabbit-broker -u dripline --password dripline
Massif arguments:   --stacks=yes --time-unit=ms
ms_print arguments: massif.out.447
--------------------------------------------------------------------------------


    MB
4.441^                         #                                              
     |   ::                 :  #                               :@           : 
     |   :                  :  #                               :@           : 
     |  :: ::::::::@::::::@@:::#:::::@@:::::::::@@::::::::::::::@:::@::::::@::
     |  :: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
     | ::: ::: ::: @::: ::@ :: #::: :@ :: :: :::@ :::::: ::: :::@: :@::::::@::
   0 +----------------------------------------------------------------------->s
     0                                                                   369.5

Number of snapshots: 61
 Detailed snapshots: [10, 16, 19 (peak), 24, 32, 45, 48, 57]

There was a bug in the receiver::handle_message_chunk() function. The first part of the ID field in each AMQP message is a UUID that's unique for each DL message. It's the key to a map to "incoming message packs," which hold the individual AMQP messages that make up any given DL message before the latter is handled. When all AMQP messages for a DL messages arrive, the message pack and the UUID are supposed to be passed to the receiver::processes_message_pack() function to turn it into a DL message and further handle it. Unfortunately, I had used the unparsed AMQP MessageId field, which contains the UUID plus information about which AMQP message in the set of 1+ AMQP messages that make up a single DL message a given AMQP message is. Therefore process_message_pack() was not properly removing the used incoming message pack from the incoming-message pack map; the map kept growing with every message received, hence the size of the application kept growing. With the fix, the message packs are deleted and the overall memory usage stays flat.