Yubico Forum

Waking up in 0.9 seconds.
Thread 1 got semaphore
Thread 1 handling request 9, (2 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 10
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_perl: Added pair NAS-Port-Type = Wireless-802.11
rlm_perl: Added pair Calling-Station-Id = 00-21-6A-84-92-C2
rlm_perl: Added pair Called-Station-Id = C0-EA-E4-46-9E-F5:wireless4
rlm_perl: Added pair Message-Authenticator = 0xf61d4fa204093b1bae6d66b70b9c5ad3
rlm_perl: Added pair User-Name = user3
rlm_perl: Added pair EAP-Message = 0x0201000a016f72696f6e
rlm_perl: Added pair Connect-Info = CONNECT 0Mbps 802.11
rlm_perl: Added pair EAP-Type = Identity
rlm_perl: Added pair NAS-IP-Address = 192.168.170.1
rlm_perl: Added pair NAS-Port = 0
rlm_perl: Added pair Framed-MTU = 1400
rlm_perl: Added pair Auth-Type = EAP
++[perl] returns ok
[files] users: Matched entry DEFAULT at line 147
++[files] returns ok
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Finished request 9.
Going to the next request
Thread 1 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 5 got semaphore
Thread 5 handling request 10, (3 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_perl: Added pair NAS-Port-Type = Wireless-802.11
rlm_perl: Added pair State = 0x5f7ed3555f7cd7753e5bec7f8de022ee
rlm_perl: Added pair Calling-Station-Id = 00-21-6A-84-92-C2
rlm_perl: Added pair Called-Station-Id = C0-EA-E4-46-9E-F5:wireless4
rlm_perl: Added pair Message-Authenticator = 0xe93c520fd1accbe08ba8b2c0fe0c80d3
rlm_perl: Added pair User-Name = user3
rlm_perl: Added pair EAP-Message = 0x020200060319
rlm_perl: Added pair Connect-Info = CONNECT 0Mbps 802.11
rlm_perl: Added pair EAP-Type = NAK
rlm_perl: Added pair NAS-IP-Address = 192.168.170.1
rlm_perl: Added pair NAS-Port = 0
rlm_perl: Added pair Framed-MTU = 1400
rlm_perl: Added pair Auth-Type = EAP
++[perl] returns ok
[files] users: Matched entry DEFAULT at line 147
++[files] returns ok
[pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Finished request 10.
Going to the next request
Thread 5 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 4 got semaphore
Thread 4 handling request 11, (3 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 105
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 95
[peap] Length Included
[peap] eaptls_verify returned 11
[peap]     (other): before/accept initialization
[peap]     TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 005a], ClientHello 
[peap]     TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello 
[peap]     TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 02b9], Certificate 
[peap]     TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone 
[peap]     TLS_accept: SSLv3 write server done A
[peap]     TLS_accept: SSLv3 flush data
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode 
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Finished request 11.
Going to the next request
Thread 4 waiting to be assigned a request
Waking up in 0.8 seconds.
Thread 3 got semaphore
Thread 3 handling request 12, (3 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 4 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 198
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange 
[peap]     TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] 
[peap] <<< TLS 1.0 Handshake [length 0010], Finished 
[peap]     TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] 
[peap]     TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished 
[peap]     TLS_accept: SSLv3 write finished A
[peap]     TLS_accept: SSLv3 flush data
[peap]     (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Finished request 12.
Going to the next request
Thread 3 waiting to be assigned a request
Waking up in 3.9 seconds.
Waking up in 0.9 seconds.
Thread 2 got semaphore
Thread 2 handling request 13, (3 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
++[eap] returns handled
Finished request 13.
Going to the next request
Thread 2 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 1 got semaphore
Thread 1 handling request 14, (3 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 6 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - user3
[peap] Got inner identity 'user3'
[peap] Setting default EAP type for tunneled EAP session.
  PEAP: Setting User-Name to user3
# Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 6 length 10
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_perl: Added pair User-Name = user3
rlm_perl: Added pair EAP-Message = 0x0206000a016f72696f6e
rlm_perl: Added pair EAP-Type = Identity
rlm_perl: Added pair FreeRADIUS-Proxied-To = 127.0.0.1
rlm_perl: Added pair Auth-Type = EAP
rlm_perl: Added pair Proxy-To-Realm = LOCAL
rlm_perl: Added pair EAP-Type = Generic-Token-Card
++[perl] returns ok
[files] users: Matched entry DEFAULT at line 147
++[files] returns ok
[ldap] performing user authorization for user3
[ldap]    expand: (uid=%{mschap:User-Name:-%{User-Name}}) -> (uid=user3)
[ldap]    expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=user3)
[ldap] No default NMAS login sequence
[ldap] looking for check items in directory...
  [ldap] userPassword -> Cleartext-Password == "test"
  [ldap] userPassword -> Password-With-Header == "test"
[ldap] looking for reply items in directory...
[ldap] user user3 authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
[pap] Config already contains "known good" password.  Ignoring Password-With-Header
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group EAP {...}
[eap] EAP Identity
[eap] processing type gtc
++[eap] returns handled
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Finished request 14.
Going to the next request
Thread 1 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 5 got semaphore
Thread 5 handling request 15, (4 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type nak
  PEAP: Setting User-Name to user3
# Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 7 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_perl: Added pair User-Name = user3
rlm_perl: Added pair EAP-Message = 0x02070006031a
rlm_perl: Added pair EAP-Type = NAK
rlm_perl: Added pair State = 0xe2abd2cee2acd41be1a92d5f2a444a2b
rlm_perl: Added pair FreeRADIUS-Proxied-To = 127.0.0.1
rlm_perl: Added pair Auth-Type = EAP
rlm_perl: Added pair Proxy-To-Realm = LOCAL
++[perl] returns ok
[files] users: Matched entry DEFAULT at line 147
++[files] returns ok
[ldap] performing user authorization for user3
[ldap]    expand: (uid=%{mschap:User-Name:-%{User-Name}}) -> (uid=user3)
[ldap]    expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=user3)
[ldap] No default NMAS login sequence
[ldap] looking for check items in directory...
  [ldap] userPassword -> Cleartext-Password == "test"
  [ldap] userPassword -> Password-With-Header == "test"
[ldap] looking for reply items in directory...
[ldap] user user3 authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
[pap] Config already contains "known good" password.  Ignoring Password-With-Header
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/mschapv2
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Finished request 15.
Going to the next request
Thread 5 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 4 got semaphore
Thread 4 handling request 16, (4 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 8 length 107
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
  PEAP: Setting User-Name to user3
# Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 8 length 64
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_perl: Added pair User-Name = user3
rlm_perl: Added pair EAP-Message = 0x020800401a0208003b31545386ce4bc457831cd63988df882aa40000000000000000653717bb321e3a98822dafcac8ecd77033cb3b7be768cfc3006f72696f6e
rlm_perl: Added pair EAP-Type = MS-CHAP-V2
rlm_perl: Added pair State = 0xe2abd2cee3a3c81be1a92d5f2a444a2b
rlm_perl: Added pair FreeRADIUS-Proxied-To = 127.0.0.1
rlm_perl: Added pair Auth-Type = EAP
rlm_perl: Added pair Proxy-To-Realm = LOCAL
++[perl] returns ok
[files] users: Matched entry DEFAULT at line 147
++[files] returns ok
[ldap] performing user authorization for user3
[ldap]    expand: (uid=%{mschap:User-Name:-%{User-Name}}) -> (uid=user3)
[ldap]    expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=user3)
[ldap] No default NMAS login sequence
[ldap] looking for check items in directory...
  [ldap] userPassword -> Cleartext-Password == "test"
  [ldap] userPassword -> Password-With-Header == "test"
[ldap] looking for reply items in directory...
[ldap] user user3 authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
[pap] Config already contains "known good" password.  Ignoring Password-With-Header
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
[mschapv2] +- entering group MS-CHAP {...}
[mschap] Creating challenge hash with username: user3
[mschap] Told to do MS-CHAPv2 for user3 with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Finished request 16.
Going to the next request
Thread 4 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 3 got semaphore
Thread 3 handling request 17, (4 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 9 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
  PEAP: Setting User-Name to user3
# Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group authorize {...}
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 9 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_perl: Added pair User-Name = user3
rlm_perl: Added pair EAP-Message = 0x020900061a03
rlm_perl: Added pair EAP-Type = MS-CHAP-V2
rlm_perl: Added pair State = 0xe2abd2cee0a2c81be1a92d5f2a444a2b
rlm_perl: Added pair FreeRADIUS-Proxied-To = 127.0.0.1
rlm_perl: Added pair Auth-Type = EAP
rlm_perl: Added pair Proxy-To-Realm = LOCAL
++[perl] returns ok
[files] users: Matched entry DEFAULT at line 147
++[files] returns ok
[ldap] performing user authorization for user3
[ldap]    expand: (uid=%{mschap:User-Name:-%{User-Name}}) -> (uid=user3)
[ldap]    expand: dc=example,dc=com -> dc=example,dc=com
  [ldap] ldap_get_conn: Checking Id: 0
  [ldap] ldap_get_conn: Got Id: 0
  [ldap] performing search in dc=example,dc=com, with filter (uid=user3)
[ldap] No default NMAS login sequence
[ldap] looking for check items in directory...
  [ldap] userPassword -> Cleartext-Password == "test"
  [ldap] userPassword -> Password-With-Header == "test"
[ldap] looking for reply items in directory...
[ldap] user user3 authorized to use remote access
  [ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
[pap] Config already contains "known good" password.  Ignoring Password-With-Header
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] returns ok
  WARNING: Empty post-auth section.  Using default return values.
# Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel
[peap] Tunneled authentication was successful.
[peap] SUCCESS
++[eap] returns handled
Finished request 17.
Going to the next request
Thread 3 waiting to be assigned a request
Waking up in 0.9 seconds.
Thread 2 got semaphore
Thread 2 handling request 18, (4 handled so far)
[<thread>] # Executing section authorize from file /etc/freeradius/sites-enabled/default
[<thread>] +- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "user3", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 10 length 43
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/default
+- entering group EAP {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state send tlv success
[peap] Received EAP-TLV response.
[peap] Success
[eap] Freeing handler
++[eap] returns ok
# Executing section post-auth from file /etc/freeradius/sites-enabled/default
+- entering group post-auth {...}
++[exec] returns noop
Finished request 18.
Going to the next request
Thread 2 waiting to be assigned a request
Waking up in 2.1 seconds.
Cleaning up request 9 ID 177 with timestamp +1121
Cleaning up request 10 ID 178 with timestamp +1121
Cleaning up request 11 ID 179 with timestamp +1121
Cleaning up request 12 ID 180 with timestamp +1121
Waking up in 1.7 seconds.
Cleaning up request 13 ID 181 with timestamp +1123
Cleaning up request 14 ID 182 with timestamp +1123
Cleaning up request 15 ID 183 with timestamp +1123
Cleaning up request 16 ID 184 with timestamp +1123
Cleaning up request 17 ID 185 with timestamp +1123
Cleaning up request 18 ID 186 with timestamp +1123
Ready to process requests.