Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-15273

High load due to system calls when calling a native method (ECDSASignature)

    XMLWordPrintable

Details

    • Bug
    • Resolution: Unresolved
    • Major
    • None
    • 11.0.0.Final, 12.0.0.Final, 13.0.0.Final, 14.0.0.Final, 15.0.1.Final, 16.0.0.Final, 17.0.1.Final, 18.0.1.Final, 19.1.0.Final, 20.0.1.Final, 21.0.2.Final, 22.0.1.Final, 23.0.2.Final, 24.0.0.Final
    • REST
    • None
    • Hide

      This can be reproduced with the application attached to this ticket: jaxrs-ecdsa521-jwt.zip

      This application implements a JWT based authentication with jose4j.

      How to run it

      $ ./gradlew assemble

# Wildfly 10
$ docker run --rm \
    -p 8080:8080 \
    -v (pwd)/app/build/libs/app.war:/opt/jboss/wildfly/standalone/deployments/app.war 
    jboss/wildfly:10.1.0.Final

# Wildfly 23
$ docker run --rm \
    -p 8080:8080 \
    -v (pwd)/app/build/libs/app.war:/opt/jboss/wildfly/standalone/deployments/app.war 
    jboss/wildfly:23.0.2.Final

      How to test it

      # Start top to analyse the number of syscalls
$ top
%Cpu(s):  2,0 us,  2,0 sy,  0,0 ni, 95,2 id,  0,0 wa,  0,0 hi,  0,7 si,  0,0 st
KiB Mem : 16312720 total,  6393388 free,  3675200 used,  6244132 buff/cache
KiB Swap: 16691196 total, 15754468 free,   936728 used. 11514368 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND    


# On a separate terminal start Apache HTTP server benchmarking tool
$ export TOKEN=$(curl http://localhost:8080/app/api/token)
$ ab  -c 80 -n 32000 \
    -m GET \
    -H "Authorization: Bearer $TOKEN" \
    http://localhost:8080/app/api/secure
      Show
      This can be reproduced with the application attached to this ticket: jaxrs-ecdsa521-jwt.zip This application implements a JWT based authentication with jose4j. How to run it $ ./gradlew assemble # Wildfly 10 $ docker run --rm \ -p 8080:8080 \ -v (pwd)/app/build/libs/app.war:/opt/jboss/wildfly/standalone/deployments/app.war jboss/wildfly:10.1.0.Final # Wildfly 23 $ docker run --rm \ -p 8080:8080 \ -v (pwd)/app/build/libs/app.war:/opt/jboss/wildfly/standalone/deployments/app.war     jboss/wildfly:23.0.2.Final How to test it # Start top to analyse the number of syscalls $ top %Cpu(s): 2,0 us, 2,0 sy, 0,0 ni, 95,2 id, 0,0 wa, 0,0 hi, 0,7 si, 0,0 st KiB Mem : 16312720 total, 6393388 free, 3675200 used, 6244132 buff/cache KiB Swap: 16691196 total, 15754468 free, 936728 used. 11514368 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND # On a separate terminal start Apache HTTP server benchmarking tool $ export TOKEN=$(curl http://localhost:8080/app/api/token) $ ab -c 80 -n 32000 \ -m GET \ -H "Authorization: Bearer $TOKEN " \     http://localhost:8080/app/api/secure

    Description

      After Wildfly 10, multiple parallel calls to verify an ECDSASignature became much slower.

      Analyzing the thread dumps.
      Multiple threads are waiting on the JDK native method sun.security.ec.ECDSASignature.verifySignedDigest:

      at sun.security.ec.ECDSASignature.verifySignedDigest(Native Method) 
at sun.security.ec.ECDSASignature.engineVerify(ECDSASignature.java:408) 
at java.security.Signature$Delegate.engineVerify(Signature.java:1394) 
at java.security.Signature.verify(Signature.java:771) 
at org.jose4j.jws.BaseSignatureAlgorithm.verifySignature(BaseSignatureAlgorithm.java:60) 
at org.jose4j.jws.EcdsaUsingShaAlgorithm.verifySignature(EcdsaUsingShaAlgorithm.java:63) 
at org.jose4j.jws.JsonWebSignature.verifySignature(JsonWebSignature.java:192) 
at org.jose4j.jwt.consumer.JwtConsumer.processContext(JwtConsumer.java:214) 
at org.jose4j.jwt.consumer.JwtConsumer.process(JwtConsumer.java:416)

      Analyzing the CPU usage difference between WildFly versions 10.1.0 and later versions.
      On later versions the application spends nearly half the time in system calls:

      • Wildfly 10.1.0.Final (4.8 sy) 
        top - 21:28:48 up 6 days, 12:00,  5 users,  load average: 5,71, 1,55, 0,74
Tasks: 348 total,   1 running, 347 sleeping,   0 stopped,   0 zombie
%Cpu(s): 91,6 us,  4,8 sy,  0,0 ni,  2,1 id,  0,0 wa,  0,0 hi,  1,5 si,  0,0 st
KiB Mem : 16312720 total,  2065968 free,  4786336 used,  9460416 buff/cache
KiB Swap: 16691196 total, 15784436 free,   906760 used. 10043116 avail Mem
      • Wildfly 11.0.0.Final (45.7 sy) 
        top - 21:32:07 up 6 days, 12:03,  5 users,  load average: 19,93, 6,37, 2,63
Tasks: 364 total,   1 running, 363 sleeping,   0 stopped,   0 zombie
%Cpu(s): 52,6 us, 45,7 sy,  0,0 ni,  1,0 id,  0,0 wa,  0,0 hi,  0,6 si,  0,0 st
KiB Mem : 16312720 total,  1808660 free,  4820144 used,  9683916 buff/cache
KiB Swap: 16691196 total, 15784948 free,   906248 used.  9983832 avail Mem

      Running later versions of WildFly with other JDK distributions (eg. Zulu or AdoptJDK) or with the same JDK version as WildFly 10.1.0.Final doesn't change this behavior.

       

      Attachments

        Activity

          People

            rsigal@redhat.com Ronald Sigal
            ricardogls Ricardo Santos (Inactive)
            Votes:
            3 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated: