Global Security Forum

------------------------------
Amogh Blue
------------------------------

Interesting finding....

It is not clear to me whether your testcase is running under the dispatcher or a "normal" SDI instance and as I am somewhat overloaded I will not be able to check right now - can you clarify that ? 

The reason is that the dispatcher is sometimes restricting things - and it is important to find out whether this is a problem in the core SDI or in the dispatcher.

PS. I would recommend using the Verify Forum for SDI and ISVG discussions as they are part of the Verify suite of products. 

------------------------------
Franz Wolfhagen
WW IAM Solution Engineer - Certified Consulting IT Specialist
IBM Security Expert Labs
------------------------------

Original Message:
Sent: Tue May 07, 2024 08:27 AM
From: Amogh Blue
Subject: SDI v7.2.0.12 log4j2 bug

Hello!

 

Found out logging problems in SDI after upgrading to log4j2 (since fixpack 8; current fixpack with malfunctioning logging - 12). First, I noticed that some logs from ISIM adapters are missing, especially during reconciliation.

I've made a test service profile, which wrote 500000 lines to log during reconciliation, created several service instances and scheduled them to run at the same time. As the result, first 4 reconciliations to be started wrote messages to logs correctly. But when 5th thread starts, it seems to drop logging of previously started threads. Moreover, sometimes the final thread also does not print full logging information expected.

Test java application, which uses log4j2, doesn't show such behaviour: tested up to 10 threads, that successfully wrote every message to log.

 

Here's a proof of concept: test win32 service containing two ALs. One of them (Thread) writes messages to logs, while the other (Service) starts several Thread ALs.

If only 1 thread is started, in writes all 500000 messages.

If there are 2 to 4 threads, fitst 1..3 of them write 500000 messages, and the final one MAY stop at 400k+ messages. Or may write everything as well.

Finally, if there are 5 of more threads, almost none of them makes it up to 500000 messages.

Files to reproduce included. I think, this is a serious security issue, as messages with critical information may be randomly missing from log.

------------------------------
Amogh Blue
------------------------------

Hello, Franz!

First this behaviour was noticed in timsol service logs (i.e. RMI dispatcer) during ISIM reconciliations or account add/modify operations. But then reproduced without dispatcher in a standalone ibmdiservice service - the one I attached configuration files from.

------------------------------
Amogh Blue
------------------------------

Original Message:
Sent: Wed May 08, 2024 02:51 AM
From: Franz Wolfhagen
Subject: SDI v7.2.0.12 log4j2 bug

Interesting finding....

It is not clear to me whether your testcase is running under the dispatcher or a "normal" SDI instance and as I am somewhat overloaded I will not be able to check right now - can you clarify that ? 

The reason is that the dispatcher is sometimes restricting things - and it is important to find out whether this is a problem in the core SDI or in the dispatcher.

PS. I would recommend using the Verify Forum for SDI and ISVG discussions as they are part of the Verify suite of products. 

------------------------------
Franz Wolfhagen
WW IAM Solution Engineer - Certified Consulting IT Specialist
IBM Security Expert Labs

Original Message:
Sent: Tue May 07, 2024 08:27 AM
From: Amogh Blue
Subject: SDI v7.2.0.12 log4j2 bug

Hello!

 

Found out logging problems in SDI after upgrading to log4j2 (since fixpack 8; current fixpack with malfunctioning logging - 12). First, I noticed that some logs from ISIM adapters are missing, especially during reconciliation.

I've made a test service profile, which wrote 500000 lines to log during reconciliation, created several service instances and scheduled them to run at the same time. As the result, first 4 reconciliations to be started wrote messages to logs correctly. But when 5th thread starts, it seems to drop logging of previously started threads. Moreover, sometimes the final thread also does not print full logging information expected.

Test java application, which uses log4j2, doesn't show such behaviour: tested up to 10 threads, that successfully wrote every message to log.

 

Here's a proof of concept: test win32 service containing two ALs. One of them (Thread) writes messages to logs, while the other (Service) starts several Thread ALs.

If only 1 thread is started, in writes all 500000 messages.

If there are 2 to 4 threads, fitst 1..3 of them write 500000 messages, and the final one MAY stop at 400k+ messages. Or may write everything as well.

Finally, if there are 5 of more threads, almost none of them makes it up to 500000 messages.

Files to reproduce included. I think, this is a serious security issue, as messages with critical information may be randomly missing from log.

------------------------------
Amogh Blue
------------------------------

Hi Amogh,

I also have same query that Franz has asked. Are you running AL in SDI or in Dispatcher?

For now, I have downloaded your attached files and have stated 'Service' AL which calls 'Thread' AL. I will observe the log file contents and get back to you.

------------------------------
Pradnya Gandhe
------------------------------

Original Message:
Sent: Tue May 07, 2024 08:27 AM
From: Amogh Blue
Subject: SDI v7.2.0.12 log4j2 bug

Hello!

 

Found out logging problems in SDI after upgrading to log4j2 (since fixpack 8; current fixpack with malfunctioning logging - 12). First, I noticed that some logs from ISIM adapters are missing, especially during reconciliation.

I've made a test service profile, which wrote 500000 lines to log during reconciliation, created several service instances and scheduled them to run at the same time. As the result, first 4 reconciliations to be started wrote messages to logs correctly. But when 5th thread starts, it seems to drop logging of previously started threads. Moreover, sometimes the final thread also does not print full logging information expected.

Test java application, which uses log4j2, doesn't show such behaviour: tested up to 10 threads, that successfully wrote every message to log.

 

Here's a proof of concept: test win32 service containing two ALs. One of them (Thread) writes messages to logs, while the other (Service) starts several Thread ALs.

If only 1 thread is started, in writes all 500000 messages.

If there are 2 to 4 threads, fitst 1..3 of them write 500000 messages, and the final one MAY stop at 400k+ messages. Or may write everything as well.

Finally, if there are 5 of more threads, almost none of them makes it up to 500000 messages.

Files to reproduce included. I think, this is a serious security issue, as messages with critical information may be randomly missing from log.

------------------------------
Amogh Blue
------------------------------

Hello, Pradnya!

The issue with logs happens both with RMI dispatcher and without. The files I attached are from standalone ibmdiservice win32 service.

------------------------------
Amogh Blue
------------------------------

Original Message:
Sent: Thu May 09, 2024 05:22 AM
From: Pradnya Gandhe
Subject: SDI v7.2.0.12 log4j2 bug

Hi Amogh,

I also have same query that Franz has asked. Are you running AL in SDI or in Dispatcher?

For now, I have downloaded your attached files and have stated 'Service' AL which calls 'Thread' AL. I will observe the log file contents and get back to you.

------------------------------
Pradnya Gandhe

Original Message:
Sent: Tue May 07, 2024 08:27 AM
From: Amogh Blue
Subject: SDI v7.2.0.12 log4j2 bug

Hello!

 

Found out logging problems in SDI after upgrading to log4j2 (since fixpack 8; current fixpack with malfunctioning logging - 12). First, I noticed that some logs from ISIM adapters are missing, especially during reconciliation.

I've made a test service profile, which wrote 500000 lines to log during reconciliation, created several service instances and scheduled them to run at the same time. As the result, first 4 reconciliations to be started wrote messages to logs correctly. But when 5th thread starts, it seems to drop logging of previously started threads. Moreover, sometimes the final thread also does not print full logging information expected.

Test java application, which uses log4j2, doesn't show such behaviour: tested up to 10 threads, that successfully wrote every message to log.

 

Here's a proof of concept: test win32 service containing two ALs. One of them (Thread) writes messages to logs, while the other (Service) starts several Thread ALs.

If only 1 thread is started, in writes all 500000 messages.

If there are 2 to 4 threads, fitst 1..3 of them write 500000 messages, and the final one MAY stop at 400k+ messages. Or may write everything as well.

Finally, if there are 5 of more threads, almost none of them makes it up to 500000 messages.

Files to reproduce included. I think, this is a serious security issue, as messages with critical information may be randomly missing from log.

------------------------------
Amogh Blue
------------------------------

Hello Amogh,

I ran your sample today and wanted to ask if you have com.ibm.di.logging.close=false set in the environment? This parameter was added in FP0011. With the parameter set, I'm seeing consistent results. 

I used your sample today and would like to ask if the environment is configured with the setting com.ibm.di.logging.close=false? This parameter was introduced in FP0011. With the parameter set to false, I see consistent positive results. Let us know your results. 

# without com.ibm.di.logging.close=false, I consistently only see 1 instance of 500,000 returned from the log files. 

$ ls -al
total 407236
drwxr-xr-x.  2 root root        80 May 14 10:13 .
drwxrwxr-x. 11 root root      4096 May 14 10:13 ..
-rw-r--r--.  1 root root 104857664 May 14 10:13 ibmdi-1.log
-rw-r--r--.  1 root root 104857664 May 14 10:13 ibmdi-2.log
-rw-r--r--.  1 root root 104857660 May 14 10:13 ibmdi-3.log
-rw-r--r--.  1 root root 102419546 May 14 10:13 ibmdi.log

$ grep -r 500000 .
./ibmdi.log:2024-05-14 10:13:27,970 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread 0CRoA: 500000
$

# with com.ibm.di.logging.close=false, I consistently see all 10 threads return 500,000

$ ls -al
total 442324
drwxr-xr-x.  2 root root        99 May 14 10:10 .
drwxrwxr-x. 11 root root      4096 May 14 10:09 ..
-rw-r--r--.  1 root root 104857664 May 14 10:10 ibmdi-1.log
-rw-r--r--.  1 root root 104857664 May 14 10:10 ibmdi-2.log
-rw-r--r--.  1 root root 104857664 May 14 10:10 ibmdi-3.log
-rw-r--r--.  1 root root 104857660 May 14 10:10 ibmdi-4.log
-rw-r--r--.  1 root root  24482267 May 14 10:10 ibmdi.log

$ grep -r 500000 .
./ibmdi.log:2024-05-14 10:10:45,399 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread UTBVM: 500000
./ibmdi.log:2024-05-14 10:10:45,484 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread fxbyg: 500000
./ibmdi.log:2024-05-14 10:10:45,653 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread AESqe: 500000
./ibmdi.log:2024-05-14 10:10:45,666 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread wl6pO: 500000
./ibmdi.log:2024-05-14 10:10:45,698 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread jCAUb: 500000
./ibmdi.log:2024-05-14 10:10:45,703 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread QlkHX: 500000
./ibmdi.log:2024-05-14 10:10:45,779 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread jL8WL: 500000
./ibmdi.log:2024-05-14 10:10:45,780 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread olW60: 500000
./ibmdi.log:2024-05-14 10:10:45,809 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread 90Dnc: 500000
./ibmdi.log:2024-05-14 10:10:45,812 INFO  [AssemblyLine.AssemblyLines/Thread] - Thread lRGEQ: 500000

------------------------------
Jason Williams
IAM Support Engineer
IBM
Tulsa OK
------------------------------

Original Message:
Sent: Tue May 07, 2024 08:27 AM
From: Amogh Blue
Subject: SDI v7.2.0.12 log4j2 bug

Hello!

 

Found out logging problems in SDI after upgrading to log4j2 (since fixpack 8; current fixpack with malfunctioning logging - 12). First, I noticed that some logs from ISIM adapters are missing, especially during reconciliation.

I've made a test service profile, which wrote 500000 lines to log during reconciliation, created several service instances and scheduled them to run at the same time. As the result, first 4 reconciliations to be started wrote messages to logs correctly. But when 5th thread starts, it seems to drop logging of previously started threads. Moreover, sometimes the final thread also does not print full logging information expected.

Test java application, which uses log4j2, doesn't show such behaviour: tested up to 10 threads, that successfully wrote every message to log.

 

Here's a proof of concept: test win32 service containing two ALs. One of them (Thread) writes messages to logs, while the other (Service) starts several Thread ALs.

If only 1 thread is started, in writes all 500000 messages.

If there are 2 to 4 threads, fitst 1..3 of them write 500000 messages, and the final one MAY stop at 400k+ messages. Or may write everything as well.

Finally, if there are 5 of more threads, almost none of them makes it up to 500000 messages.

Files to reproduce included. I think, this is a serious security issue, as messages with critical information may be randomly missing from log.

------------------------------
Amogh Blue
------------------------------