cisagov / icsnpp-bacnet

Zeek BACnet Parser - CISA ICSNPP
BSD 3-Clause "New" or "Revised" License
15 stars 11 forks source link

Log missing for packet with message fragment (Issue #29) #39

Closed kkvarfordt closed 3 months ago

kkvarfordt commented 3 months ago

🗣 Description

Log is missing packet No. 15. This is due to the data for a read property ack being fragmented over packets 15, 17, and 18.

💭 Motivation and context

Fix for issue #29. Modified the code base to check for the is_segmented and more_follows flags. If the data is segmented, then a data buffer is constructed to hold the segmented data before processing continues.

🧪 Testing

Exported frames 15, 17, and 18 from the test.pcap attached to issue #29. Using the exported data (test_frame_15_17_18.pcap) as input to the parser, verified the segmented data is correctly buffered and processed resulting in all the data being logged.

test_frame_15_17_18.pcap.zip

kkvarfordt commented 3 months ago

Unit tests fail when installing via zkg

Specifically, unit test fail when installing via zkg in a Zeek environment that has debug information enabled. This is unfortunately a side effect of the fragmented data implementation/solution. Below is a breakdown of the issue and the cause.

Problem Description:

When installing the icsnpp-bacnet parser with a Zeek instance that has been compiled with debug settings, the installation btest(s) fail and the parser is not installed. Specifically, the analyzer.segmented_data and analyzer.services test fail. These tests use the bacnet_segmented_data.pcap and bacnet_services.pcap as input.

Error:

root@71502a668c2e:~/projects/icsnpp-bacnet_segmented-data_docker-clean# zkg install .
The following packages will be INSTALLED:
  /root/projects/icsnpp-bacnet_segmented-data_docker-clean (segmented_data)

Proceed? [Y/n] 
Running unit tests for "/root/projects/icsnpp-bacnet_segmented-data_docker-clean"
error: failed to run tests for /root/projects/icsnpp-bacnet_segmented-data_docker-clean: test_command failed with exit code 1
Proceed to install anyway? [N/y] N
Abort.
root@71502a668c2e:~/projects/icsnpp-bacnet_segmented-data_docker-clean# 

Debugging:

Cloning the code base and building from scratch followed by running zeek -Cr ./test/traces/bacnet_segmented_data.pap icsnpp/bacnet shows the parser aborts with the following message:

zeek: ./build/bacnet_pac.h:1156: vector<binpac::BACNET::BACnet_Tag *> *binpac::BACNET::Complex_ACK_PDU::service_ack_tags() const: Assertion `has_service_ack_tags()' failed.
Aborted (core dumped)

File ./build/bacnet_pac.h at line 1156 shows:

1155         const_bytestring const & service_tag_buffer() const { return service_tag_buffer_; }
1156         vector<BACnet_Tag *> * service_ack_tags() const { BINPAC_ASSERT(has_service_ack_tags()); return service_ack_tags_; }
1157         bool has_service_ack_tags() const { return has_service_ack_tags_; }

This code block is part of class Complex_ACK_PDU. Research into the BINPAC_ASSERT functionality shows it is just a redefination of the C++ assert functionality. As explained in the C++ assert documentation "If NDEBUG is defined as a macro name at the point in the source code where or is included, the assertion is disabled: assert does nothing." This explains whey this error is encountered only when running under the Zeek instance that has been compiled with debug settings.

Digging deeper into class Complex_ACK_PDU as implemented in files ./build/bacnet_pac.h and ./build/bacnet_pac.cc shows service_ack_tags() is called in the Complex_ACK_PDU::Parse method and the Complex_ACK_PDU::~Complex_ACK_PDU() destructor.

Code Complex_ACK_PDU::Parse

2202 // Evaluate 'let' and 'withinput' fields
2203 is_segmented_ =  (  ( choice_tag() & 0x8 )  >> 3 ) ;
2204 more_follows_ =  (  ( choice_tag() & 0x4 )  >> 2 ) ;
2205 service_tag_buffer_ = t_context->flow()->buffer_service_tags(service_tag_data(), more_follows());
2206 has_service_ack_tags_ =  ( more_follows() == 0 ) ;
2207 if ( has_service_ack_tags() )
2208         {
2209         service_ack_tags_ = t_context->flow()->process_service_tags(service_tag_buffer());
2210         }
2211 has_deliver_ =  ( more_follows() == 0 ) ;
2212 if ( has_deliver() )
2213         {
2214         bool t_t_var_003;
2215         switch ( service_choice() )
2216                 {
2217                 case ((uint8) 3):
2218                         t_t_var_003 = t_context->flow()->process_get_alarm_summary_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2219                         break;
2220                 case ((uint8) 4):
2221                         t_t_var_003 = t_context->flow()->process_get_enrollment_summary_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2222                         break;
2223                 case ((uint8) 6):
2224                         t_t_var_003 = t_context->flow()->process_atomic_read_file_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2225                 break;
2226                 case ((uint8) 7):
2227                         t_t_var_003 = t_context->flow()->process_atomic_write_file_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2228                         break;
2229                 case ((uint8) 10):
2230                         t_t_var_003 = t_context->flow()->process_create_object_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2231                         break;
2232                 case ((uint8) 12):
2233                         t_t_var_003 = t_context->flow()->process_read_property_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2234                         break;
2235                 case ((uint8) 13):
2236                         t_t_var_003 = false;
2237                         break;
2238                 case ((uint8) 14):
2239                         t_t_var_003 = t_context->flow()->process_read_property_multiple_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2240                         break;
2241                 case ((uint8) 18):
2242                         t_t_var_003 = t_context->flow()->process_confirmed_private_transfer_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2243                         break;
2244                 case ((uint8) 21):
2245                         t_t_var_003 = t_context->flow()->process_vt_open_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2246                         break;
2247                 case ((uint8) 23):
2248                         t_t_var_003 = t_context->flow()->process_vt_data_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2249                         break;
2250                 case ((uint8) 24):
2251                         t_t_var_003 = false;
2252                         break;
2253                 case ((uint8) 25):
2254                         t_t_var_003 = false;
2255                         break;
2256                 case ((uint8) 26):
2257                         t_t_var_003 = t_context->flow()->process_read_range_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2258                         break;
2259                 case ((uint8) 29):
2260                         t_t_var_003 = t_context->flow()->process_get_event_information_ack(is_orig(), invoke_id(), service_ack_tags()); // <==== Called here
2261                         break;
2262                 default:
2263                         t_t_var_003 = false;
2264                         break;
2265                 }

Code Complex_ACK_PDU::~Complex_ACK_PDU()

2085         service_tag_data_.free();
2086         if ( service_ack_tags() )  // <===== Called here
2087                 {
2088                 for ( auto* t_service_ack_tags__elem : *service_ack_tags() )
2089                         {
2090                         delete t_service_ack_tags__elem;
2091                         t_service_ack_tags__elem = nullptr;
2092                         }
2093                 }
2094         delete service_ack_tags_;

The thing to notice about the above calls to service_ack_tags() is that in the Complex_ACK_PDU::Parse code, these calls are essentially "protected" by code block

2207 if ( has_service_ack_tags() )
2208         {
2209         service_ack_tags_ = t_context->flow()->process_service_tags(service_tag_buffer());
2210         }
2211 has_deliver_ =  ( more_follows() == 0 ) ;
2212 if ( has_deliver() )
2213         {

This code makes sure there are service_ack_tags_ available before calling method service_ack_tags(). In the case of the Complex_ACK_PDU::~Complex_ACK_PDU() destructor, there are no such "protections" which causes the assertion to fail if no service_ack_tags_ have been allocated.

Conclusion:

This error appears to be a short coming of the Binpac implementation and resulting generated code. Given Binpac is considered obselete, there really isn't much that can be done about it. Also, the code only fails when running in the Zeek debug configuration. As a sanity check, the code was executed in a Zeek environment without debug settings and it was confirmed the code runs clean - e.g. no exceptions were thrown.

References: