Authd process and cpu at 99% - Sso Azure ko after upgrading to 7.2.7 and 7.4.3

[Maerre]

Hello folks,

in my deployment i'm using a fortigate 200F with Sso (Azure) and everything was working correctly before  upgrading from 7.0.12M to 7.2.7.
After the upgrade i'm facing that authd process is constantly consuming 97% of cpu resources and Sso is not working anymore.
Thought it was a bug so decided to upgrade newly from 7.2.7 to 7.4.3 but i still have the issue.

Tried to reboot the firewall (a HA pair) and until there are no authentication requests from clients, the cpu is ok (authd process is not present in the process list or is at 2%), as soon as there's an authetication request the authd process goes to 97% and so the cpu.
In this condition the Sso is not working, i check the configuration and nothing changed, took a debug and sniffer packet from client and all the routing is ok, checked fsso configuration both on firewall and Azure and it's ok.

Did you face something similar? Do you have any advise? The upgrade triggered something but i can't understand what is the root case and in the release note there's nothing about any incompatibility with Fsso.

Following the output:

get system performance top:
Run Time:  0 days, 3 hours and 14 minutes
97U, 0N, 1S, 1I, 0WA, 0HI, 1SI, 0ST; 3962T, 2183F
           authd      261      R      95.2     0.4    0
           authd      260      R      94.8     0.4    1
       ipsengine      342      R <     2.2     1.4    0
       ipsengine      343      S <     1.4     1.3    1
             wad      241      S       1.2     2.0    0
          httpsd     1616      S       1.0     0.4    0
         sslvpnd      190      S       0.8     1.2    1
             wad      240      R       0.4     1.9    0
            node      172      S       0.4     1.7    1
          hasync      203      S <     0.4     1.3    0
       forticron      179      S       0.2     0.7    1
          hatalk      202      S <     0.2     0.5    0
         updated      387      S       0.2     0.4    1
          fnbamd      177      S       0.2     0.4    1
           snmpd      200      S       0.2     0.3    0

FWF200 (global) # get system performance status
CPU states: 95% user 2% system 0% nice 1% idle 0% iowait 0% irq 2% softirq
CPU0 states: 94% user 3% system 0% nice 1% idle 0% iowait 0% irq 2% softirq
CPU1 states: 97% user 1% system 0% nice 1% idle 0% iowait 0% irq 1% softirq
Memory: 4057316k total, 1517896k used (37.4%), 2228268k free (54.9%), 311152k freeable (7.7%)
Average network usage: 67215 / 66085 kbps in 1 minute, 85192 / 83859 kbps in 10 minutes, 90994 / 89877 kbps in 30 minutes
Maximal network usage: 88929 / 87772 kbps in 1 minute, 164915 / 136434 kbps in 10 minutes, 180913 / 172178 kbps in 30 minutes
Average sessions: 7089 sessions in 1 minute, 7101 sessions in 10 minutes, 20449 sessions in 30 minutes
Maximal sessions: 7185 sessions in 1 minute, 7531 sessions in 10 minutes, 46646 sessions in 30 minutes
Average session setup rate: 64 sessions per second in last 1 minute, 64 sessions per second in last 10 minutes, 278 sessions per second in last 30 minutes
Maximal session setup rate: 98 sessions per second in last 1 minute, 161 sessions per second in last 10 minutes, 840 sessions per second in last 30 minutes
Average NPU sessions: 379 sessions in last 1 minute, 373 sessions in last 10 minutes, 383 sessions in last 30 minutes
Maximal NPU sessions: 402 sessions in last 1 minute, 416 sessions in last 10 minutes, 446 sessions in last 30 minutes
Virus caught: 0 total in 1 minute
IPS attacks blocked: 0 total in 1 minute
Uptime: 0 days,  3 hours,  14 minutes

FWF200 (global) # -diagnose sys top
Run Time:  0 days, 3 hours and 12 minutes
98U, 0N, 0S, 1I, 0WA, 0HI, 1SI, 0ST; 3962T, 2171F
           authd      261      R      96.5     0.4    0
           authd      260      R      96.0     0.4    1
       ipsengine      342      S <     2.5     1.4    0
       ipsengine      343      S <     1.5     1.3    1
             wad      241      S       1.0     2.0    1
             wad      240      S       0.5     1.9    0
          hasync      203      S <     0.5     1.3    1
         sslvpnd      190      S       0.5     1.2    1
         miglogd      262      S       0.5     1.1    0
  merged_daemons      175      S       0.5     0.2    0

Thank you

Regards

[smaruvala]

Hi,

- Can you try to collect the debug for authd process?

##diagnose debug application authd -1
##diagnose debug enable

- You can use the below command to disable the debug.

#diagnose debug disable

- Please check if you are observing any crashes in the device too.

#diagnose debug crashlog read

Regards,

Shiva

[Maerre]

Hi @smaruvala,

here the output about the debug:

FWF200 (root) # diagnose debug application authd -1
Debug messages will be on for 7 minutes.

FWF200 # diagnose debug enable

FWF200 # authd_epoll_work: timeout 9940
authd_timer_run: 3 expired
authd_epoll_work: timeout 60000
authd_epoll_work: timeout 9930
authd_timer_run: 3 expired
authd_epoll_work: timeout 60000
authd_epoll_work: timeout 9930
authd_timer_run: 3 expired
authd_epoll_work: timeout 60000

FWF200 (root) # diagnose debug disable

FWF200 (root) # diagnose debug crashlog read

800: 2024-03-01 10:52:21 <00710> firmware FortiGate-200E v7.4.3,build2573b2573,240201 (GA.F) (Release)
801: 2024-03-01 10:52:21 <00710> application authd2
802: 2024-03-01 10:52:21 <00710> *** signal 11 (Segmentation fault) received ***
803: 2024-03-01 10:52:21 <00710> Register dump:
804: 2024-03-01 10:52:21 <00710> RAX: 0000000000003a8e RBX: 00007ff9116a27c8
805: 2024-03-01 10:52:21 <00710> RCX: 000000000000000b RDX: 0000000000000000
806: 2024-03-01 10:52:21 <00710> R08: 00007fffffb38690 R09: 0000000000000010
807: 2024-03-01 10:52:21 <00710> R10: 0000000000000000 R11: 0000000000000246
808: 2024-03-01 10:52:21 <00710> R12: 00007ff9110a9000 R13: 00007ff911671700
809: 2024-03-01 10:52:21 <00710> R14: 00007fffffb76a30 R15: 00007ff9116f9000
810: 2024-03-01 10:52:21 <00710> RSI: 0000000000000008 RDI: 00007ff9110aca8e
811: 2024-03-01 10:52:21 <00710> RBP: 00007fffffb76b30 RSP: 00007fffffb589d8
812: 2024-03-01 10:52:21 <00710> RIP: 0000000002d8c390 EFLAGS: 0000000000000202
813: 2024-03-01 10:52:21 <00710> CS: 0033 FS: 0000 GS: 0000
814: 2024-03-01 10:52:21 <00710> Trap: 0000000000000000 Error: 0000000000000000
815: 2024-03-01 10:52:21 <00710> OldMask: 0000000000000000
816: 2024-03-01 10:52:21 <00710> CR2: 0000000000000000
817: 2024-03-01 10:52:21 <00710> stack: 0x7fffffb589d8 - 0x7fffffb77710
818: 2024-03-01 10:52:21 <00710> Backtrace:
819: 2024-03-01 10:52:21 <00710> [0x02d8c390] => /bin/authd
820: 2024-03-01 10:52:21 <00710> [0x004ac2d5] => /bin/authd
821: 2024-03-01 10:52:21 <00710> [0x004b71ee] => /bin/authd
822: 2024-03-01 10:52:21 <00710> [0x02d2a876] => /bin/authd
823: 2024-03-01 10:52:21 <00710> [0x004737a2] => /bin/authd
824: 2024-03-01 10:52:21 <00710> [0x00473aa7] => /bin/authd
825: 2024-03-01 10:52:21 <00710> [0x00473ebd] => /bin/authd
826: 2024-03-01 10:52:21 <00710> [0x0044d1bf] => /bin/authd
827: 2024-03-01 10:52:21 <00710> [0x00452a28] => /bin/authd
828: 2024-03-01 10:52:21 <00710> [0x00452e4c] => /bin/authd
829: 2024-03-01 10:52:21 <00710> [0x0045587f] => /bin/authd
830: 2024-03-01 10:52:21 <00710> [0x00456387] => /bin/authd
831: 2024-03-01 10:52:21 <00710> [0x7ff915d36deb] => /usr/lib/x86_64-linux-gnu/libc.so.6
832: 2024-03-01 10:52:21 (__libc_start_main+0x000000eb) liboffset 00023deb
833: 2024-03-01 10:52:21 <00710> [0x004489ca] => /bin/authd
834: 2024-03-01 10:52:21 <00710> fortidev 6.0.1.0005
835: 2024-03-01 10:52:23 Signal <11> was sent to process <00711> by user <paolo.capelli@growens.io>
836: 2024-03-01 10:52:23 <00711> firmware FortiGate-200E v7.4.3,build2573b2573,240201 (GA.F) (Release)
837: 2024-03-01 10:52:23 <00711> application authd3
838: 2024-03-01 10:52:23 <00711> *** signal 11 (Segmentation fault) received ***
839: 2024-03-01 10:52:23 <00711> Register dump:
840: 2024-03-01 10:52:23 <00711> RAX: 0000000000004335 RBX: 00007ff9116a2298
841: 2024-03-01 10:52:23 <00711> RCX: 000000000000000b RDX: 0000000000000000
842: 2024-03-01 10:52:23 <00711> R08: 00007fffffb38690 R09: 0000000000000010
843: 2024-03-01 10:52:23 <00711> R10: 0000000000000000 R11: 0000000000000246
844: 2024-03-01 10:52:23 <00711> R12: 00007ff911071000 R13: 00007ff911671700
845: 2024-03-01 10:52:23 <00711> R14: 00007fffffb76a30 R15: 00007ff9116f5000
846: 2024-03-01 10:52:23 <00711> RSI: 0000000000000008 RDI: 00007ff911075335
847: 2024-03-01 10:52:23 <00711> RBP: 00007fffffb76b30 RSP: 00007fffffb589d8
848: 2024-03-01 10:52:23 <00711> RIP: 0000000002d8c390 EFLAGS: 0000000000000202
849: 2024-03-01 10:52:23 <00711> CS: 0033 FS: 0000 GS: 0000
850: 2024-03-01 10:52:23 <00711> Trap: 0000000000000000 Error: 0000000000000000
851: 2024-03-01 10:52:23 <00711> OldMask: 0000000000000000
852: 2024-03-01 10:52:23 <00711> CR2: 0000000000000000
853: 2024-03-01 10:52:23 <00711> stack: 0x7fffffb589d8 - 0x7fffffb77710
854: 2024-03-01 10:52:23 <00711> Backtrace:
855: 2024-03-01 10:52:23 <00711> [0x02d8c390] => /bin/authd
856: 2024-03-01 10:52:23 <00711> [0x004ac2d5] => /bin/authd
857: 2024-03-01 10:52:23 <00711> [0x004b71ee] => /bin/authd
858: 2024-03-01 10:52:23 <00711> [0x02d2a876] => /bin/authd
859: 2024-03-01 10:52:23 <00711> [0x004737a2] => /bin/authd
860: 2024-03-01 10:52:23 <00711> [0x00473aa7] => /bin/authd
861: 2024-03-01 10:52:23 <00711> [0x00473ebd] => /bin/authd
862: 2024-03-01 10:52:23 <00711> [0x0044d1bf] => /bin/authd
863: 2024-03-01 10:52:23 <00711> [0x00452a28] => /bin/authd
864: 2024-03-01 10:52:23 <00711> [0x00452e4c] => /bin/authd
865: 2024-03-01 10:52:23 <00711> [0x0045587f] => /bin/authd
866: 2024-03-01 10:52:23 <00711> [0x00456387] => /bin/authd
867: 2024-03-01 10:52:23 <00711> [0x7ff915d36deb] => /usr/lib/x86_64-linux-gnu/libc.so.6
868: 2024-03-01 10:52:23 (__libc_start_main+0x000000eb) liboffset 00023deb
869: 2024-03-01 10:52:23 <00711> [0x004489ca] => /bin/authd
870: 2024-03-01 10:52:23 <00711> fortidev 6.0.1.0005
871: 2024-03-01 10:52:23 the killed daemon is /bin/authd: status=0x0
872: 2024-03-01 11:52:25 authd2 crashed 1 times. The latest crash was at 2024-03-01 10:52:21.
873: 2024-03-01 11:52:25 authd3 crashed 1 times. The latest crash was at 2024-03-01 10:52:23.
Crash log interval is 3600 seconds
Max crash log line number: 16384

i don't see any root cause, are they useful for you?

Thank you

[hbac]

Hi @Maerre,

It seems to be a new bug. I would suggest opening a ticket with Fortinet support to get it fixed. 

Regards, 

[Maerre]

Hi,
it's strange because it happened in the 7.2.7, however i'll open a case.

[Maerre]

A little update, after more than a month the case is still "bug pending" nd tac is not able to reproduce the issue or solve it....