privacyIDEA request failed: 500 read timeout

[cnopix]

Hi everyone,

i have a new issue

when i use otp for VPN connection, it works 1 time of 5 .

and if a check with freeradius -X command, i see this error : “privacyIDEA request failed: 500 read timeout”

But, i don’t know the reason.

Can you help me ?

Logs:

rlm_perl: Config File /etc/privacyidea/rlm_perl.ini found!

rlm_perl: Debugging config:

rlm_perl: Default URL https://localhost/validate/check

rlm_perl: Looking for config for auth-type Perl

rlm_perl: Auth-Type: Perl

rlm_perl: url: https://localhost/validate/check

rlm_perl: user sent to privacyidea: c.focant

rlm_perl: realm sent to privacyidea:

rlm_perl: resolver sent to privacyidea:

rlm_perl: client sent to privacyidea: 10.2.1.1

rlm_perl: state sent to privacyidea:

rlm_perl: urlparam client

rlm_perl: urlparam pass

rlm_perl: urlparam user

rlm_perl: Request timeout: 5

rlm_perl: Not verifying SSL certificate!

rlm_perl: elapsed time for privacyidea call: 5.079746

rlm_perl: privacyIDEA request failed: 500 read timeout

rlm_perl: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before “read timeout at /usr…”) at /usr/share/privacyidea/freeradius/privacyidea_radius.pm line 492.

rlm_perl: Can not parse response from privacyIDEA.

rlm_perl: return RLM_MODULE_FAIL

Cnopix

[cornelinux]

Look here:

500 Internal Server Error when trying to send test email

I’ve got the services installed and now am trying to get everything configured. However, every time I try to send a test email to test my SMTP configuration I’m getting a 500 Internal Server Error when it tries to POST to /smtpserver/send_test_email. Any thoughts?

always same procedure with 500 errors.

[plettich]

Actually this error is from FreeRADIUS since privacyIDEA did not answer fast enough (timeout set to 5s):

@cnopix

rlm_perl: Request timeout: 5

rlm_perl: Not verifying SSL certificate!

rlm_perl: elapsed time for privacyidea call: 5.079746

rlm_perl: privacyIDEA request failed: 500 read timeout

There is no information as to why privacyIDEA takes that long. Usually this is due to a slow resolver, db or push_wait configuration. You could start privacyIDEA with debug logging enabled which should give an idea where the hanging occurs.

[cnopix]

Thanks for the respons,

i check the post @cornelinux

@plettich, i change the timeout to 10 or 15 but privacyidea call is the same if i put 10 i have 10.05… and if i put 15 i have 15.07…

[cnopix]

this is freeradius debug :

(0) Received Access-Request Id 37 from 10.2.1.14:51457 to 10.2.1.87:1812 length 83
(0) User-Name = “usertest”
(0) User-Password = “test123”
(0) NAS-IP-Address = 10.2.1.1
(0) NAS-Port = 0
(0) Proxy-State = 0xfe800000000000005d53f0c480c4b9cc00000025
(0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/privacyidea
(0) authorize {
(0) perl-privacyidea: $RAD_REQUEST{‘User-Name’} = &request:User-Name → ‘usertest’
(0) perl-privacyidea: $RAD_REQUEST{‘User-Password’} = &request:User-Password → ‘test123’
(0) perl-privacyidea: $RAD_REQUEST{‘NAS-IP-Address’} = &request:NAS-IP-Address → ‘10.2.1.1’
(0) perl-privacyidea: $RAD_REQUEST{‘NAS-Port’} = &request:NAS-Port → ‘0’
(0) perl-privacyidea: $RAD_REQUEST{‘Proxy-State’} = &request:Proxy-State → ‘0xfe800000000000005d53f0c480c4b9cc00000025’
(0) perl-privacyidea: &request:Proxy-State = $RAD_REQUEST{‘Proxy-State’} → ‘0xfe800000000000005d53f0c480c4b9cc00000025’
(0) perl-privacyidea: &request:User-Name = $RAD_REQUEST{‘User-Name’} → ‘usertest’
(0) perl-privacyidea: &request:NAS-IP-Address = $RAD_REQUEST{‘NAS-IP-Address’} → ‘10.2.1.1’
(0) perl-privacyidea: &request:User-Password = $RAD_REQUEST{‘User-Password’} → ‘test123’
(0) perl-privacyidea: &request:NAS-Port = $RAD_REQUEST{‘NAS-Port’} → ‘0’
(0) [perl-privacyidea] = ok
(0) if (ok || updated) {
(0) if (ok || updated) → TRUE
(0) if (ok || updated) {
(0) update control {
(0) Auth-Type := Perl
(0) } # update control = noop
(0) } # if (ok || updated) = noop
(0) } # authorize = ok
(0) Found Auth-Type = Perl
(0) # Executing group from file /etc/freeradius/3.0/sites-enabled/privacyidea
(0) Auth-Type Perl {
(0) perl-privacyidea: $RAD_REQUEST{‘User-Name’} = &request:User-Name → ‘usertest’
(0) perl-privacyidea: $RAD_REQUEST{‘User-Password’} = &request:User-Password → ‘test123’
(0) perl-privacyidea: $RAD_REQUEST{‘NAS-IP-Address’} = &request:NAS-IP-Address → ‘10.2.1.1’
(0) perl-privacyidea: $RAD_REQUEST{‘NAS-Port’} = &request:NAS-Port → ‘0’
(0) perl-privacyidea: $RAD_REQUEST{‘Proxy-State’} = &request:Proxy-State → ‘0xfe800000000000005d53f0c480c4b9cc00000025’
(0) perl-privacyidea: $RAD_CHECK{‘Auth-Type’} = &control:Auth-Type → ‘Perl’
(0) perl-privacyidea: $RAD_CONFIG{‘Auth-Type’} = &control:Auth-Type → ‘Perl’
rlm_perl: Config File /etc/privacyidea/rlm_perl.ini found!
rlm_perl: Debugging config:
rlm_perl: Default URL https://localhost/validate/check
rlm_perl: Looking for config for auth-type Perl
rlm_perl: Auth-Type: Perl
rlm_perl: url: https://localhost/validate/check
rlm_perl: user sent to privacyidea: usertest
rlm_perl: realm sent to privacyidea:
rlm_perl: resolver sent to privacyidea:
rlm_perl: client sent to privacyidea: 10.2.1.1
rlm_perl: state sent to privacyidea:
rlm_perl: urlparam client
rlm_perl: urlparam pass
rlm_perl: urlparam user
rlm_perl: Request timeout: 10
rlm_perl: Not verifying SSL certificate!
rlm_perl: elapsed time for privacyidea call: 10.102844
rlm_perl: privacyIDEA request failed: 500 read timeout
rlm_perl: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before “read timeout at /usr…”) at /usr/share/privacyidea/freeradius/privacyidea_radius.pm line 492.
rlm_perl: Can not parse response from privacyIDEA.
rlm_perl: return RLM_MODULE_FAIL
(0) perl-privacyidea: &request:Proxy-State = $RAD_REQUEST{‘Proxy-State’} → ‘0xfe800000000000005d53f0c480c4b9cc00000025’
(0) perl-privacyidea: &request:User-Name = $RAD_REQUEST{‘User-Name’} → ‘usertest’
(0) perl-privacyidea: &request:NAS-IP-Address = $RAD_REQUEST{‘NAS-IP-Address’} → ‘10.2.1.1’
(0) perl-privacyidea: &request:User-Password = $RAD_REQUEST{‘User-Password’} → ‘test123’
(0) perl-privacyidea: &request:NAS-Port = $RAD_REQUEST{‘NAS-Port’} → ‘0’
(0) perl-privacyidea: &reply:Reply-Message = $RAD_REPLY{‘Reply-Message’} → ‘privacyIDEA request failed: 500 read timeout’
(0) perl-privacyidea: &control:Auth-Type = $RAD_CHECK{‘Auth-Type’} → ‘Perl’
(0) [perl-privacyidea] = fail
(0) } # Auth-Type Perl = fail
(0) Failed to authenticate the user
(0) Using Post-Auth-Type Reject
(0) Post-Auth-Type sub-section not found. Ignoring.
(0) Delaying response for 1.000000 seconds
Waking up in 0.9 seconds.
(0) Sending delayed response
(0) Sent Access-Reject Id 37 from 10.2.1.87:1812 to 10.2.1.14:51457 length 88
(0) Reply-Message = “privacyIDEA request failed: 500 read timeout”
(0) Proxy-State = 0xfe800000000000005d53f0c480c4b9cc00000025
Waking up in 3.9 seconds.
(0) Cleaning up request packet ID 37 with timestamp +68
Ready to process requests

and this is privacyidea log :

[2021-02-24 10:42:43,415][4411][140206467815168][INFO][privacyidea.lib.user:233] user ‘usertest’ found in resolver ‘AD1’

[2021-02-24 10:42:43,416][4411][140206467815168][INFO][privacyidea.lib.user:234] userid resolved to ‘c88cd461-4517-4432-860d-9575a6f65524’

[2021-02-24 10:42:43,441][4411][140206467815168][INFO][privacyidea.lib.user:360] User ‘usertest’ from realm ‘IT’ tries to authenticate

[2021-02-24 10:42:43,746][4411][140206467815168][INFO][privacyidea.lib.user:360] User ‘usertest’ from realm ‘IT’ tries to authenticate

Cnopix.

[cnopix]

i test a lot of change for timeout on mly server or on privacyidea but i don’t find a solution.

Please help

[cnopix]

anyone ?i don’t find solution :’(

[cornelinux]

• Check where you changed the timeout.
• Check what you did after changing the timeout.
• Take a look into the privacyIDEA audit log, to understand why it is taking so long. – are you using push tokens?
• Replicate the behaviour at the command line using some tools querying the REST API, (to avoid the timeout of the radius server). Be creative to investigate your problem, like a sysadmin would do.

[snatch2013]

yes, the same problem in 3.5.1
Thu Apr 1 10:36:56 2021 : Info: rlm_perl: elapsed time for privacyidea call: 10.468477
Thu Apr 1 10:36:56 2021 : rlm_perl: Content read timeout at /usr/share/perl5/Net/HTTP/Methods.pm line 268.
Thu Apr 1 10:36:56 2021 : Info: rlm_perl: privacyIDEA request failed: 500 read timeout
Thu Apr 1 10:36:56 2021 : Info: rlm_perl: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before “read timeout at /usr…”) at /usr/share/privacyidea/freeradius/privacyidea_radius.pm line 492.
Thu Apr 1 10:36:56 2021 : Info: rlm_perl: Can not parse response from privacyIDEA.

But not always, so difficult to reproduce, but will try debug in privacyidea.

[cornelinux]

See my previous post. Look into the privacyidea.log.
Your RADIUS timeout is to short and privascyIDEA does not respond within this time.
Simple as that.

[snatch2013]

Yes, sure, I have seen the answer and will try to troubleshoot it as you proposed. I have just written it to let topic starter know that he is not alone with this problem

[snatch2013]

looks like it helped in my case just to add a second core to the privacyidea container.