search

will-hart / blitz

An open source data acquisition system in Python
http://will-hart.github.io/blitz/
GNU Affero General Public License v3.0
0 stars 1 forks source link

Server blocks @ 100% CPU on "STOP" command #13

Closed will-hart closed 10 years ago

will-hart commented 10 years ago

Not sure if this is due to "STOP" command in particular (maybe waiting on thread join?) or some other TCP receiving related issue (readUntil?).

will-hart commented 10 years ago

Resolved by a3ba75f

Original Comment By: Will Hart

will-hart commented 10 years ago

Logs suggest TCP client never sends the STOP message. As this occurs in the send/receive loop, its likely that the receiver is blocking. 

2013-07-06 01:40:36,740     DEBUG      MainThread         DatabaseClient __init__
2013-07-06 01:40:36,753     INFO       MainThread         Initialised DatabaseClient
2013-07-06 01:40:36,755     INFO       MainThread         Registered expansion board [1: Blitz Basic Expansion Board]
2013-07-06 01:40:36,763     DEBUG      MainThread         HTTPServer __init__
2013-07-06 01:40:36,782     INFO       MainThread         HTTP server started listening on port 8989
2013-07-06 01:40:48,763     INFO       MainThread         200 GET / (::1) 2.00ms
2013-07-06 01:40:49,388     INFO       MainThread         200 GET /cache (::1) 3.00ms
2013-07-06 01:40:49,413     INFO       MainThread         304 GET /categories (::1) 2.00ms
2013-07-06 01:40:49,647     WARNING    MainThread         404 GET /favicon.ico (::1) 2.00ms
2013-07-06 01:40:56,540     DEBUG      MainThread         Created TCP connection at client request
2013-07-06 01:40:56,543     DEBUG      MainThread         Created TCP Client at 192.168.1.3:8999
2013-07-06 01:40:56,543     DEBUG      MainThread         [TCP] Calling base.enter_state >> ClientInitState
2013-07-06 01:40:56,545     DEBUG      MainThread         Launching TcpClient listen thread
2013-07-06 01:40:56,549     INFO       MainThread         304 GET /connect (::1) 7.00ms
2013-07-06 01:41:01,372     DEBUG      MainThread         Web client requested logging start
2013-07-06 01:41:01,372     DEBUG      MainThread         [TCP] Calling base.send_message: START
2013-07-06 01:41:01,375     INFO       MainThread         304 GET /start (::1) 2.00ms
2013-07-06 01:41:01,546     DEBUG      Thread-1           [TCP] TcpClient sending: START
2013-07-06 01:41:01,556     DEBUG      Thread-1           [TCP] TcpClient has received: ACK
2013-07-06 01:41:01,556     DEBUG      Thread-1           [TCP] Calling init.process_message: ACK
2013-07-06 01:41:01,558     DEBUG      Thread-1           [TCP] Calling base.go_to_state >> ClientLoggingState
2013-07-06 01:41:01,558     DEBUG      Thread-1           [TCP] Calling base.enter_state >> ClientLoggingState
2013-07-06 01:41:03,382     INFO       MainThread         200 GET /cache/1373071236.712 (::1) 3.00ms
2013-07-06 01:41:05,384     INFO       MainThread         304 GET /cache/1373071236.712 (::1) 5.00ms
2013-07-06 01:41:07,384     INFO       MainThread         304 GET /cache/1373071236.712 (::1) 3.00ms
2013-07-06 01:41:09,384     INFO       MainThread         304 GET /cache/1373071236.712 (::1) 3.00ms
2013-07-06 01:41:11,384     INFO       MainThread         304 GET /cache/1373071236.712 (::1) 4.00ms
2013-07-06 01:41:13,384     INFO       MainThread         304 GET /cache/1373071236.712 (::1) 3.00ms
2013-07-06 01:41:13,861     DEBUG      MainThread         Web client requested logging stop
2013-07-06 01:41:13,861     DEBUG      MainThread         [TCP] Calling logging.send_message: STOP
2013-07-06 01:41:13,861     DEBUG      MainThread         [TCP] Calling base.go_to_state >> ClientStoppingState
2013-07-06 01:41:13,861     DEBUG      MainThread         [TCP] Calling stopping.enter_state: ClientStoppingState
2013-07-06 01:41:13,862     INFO       MainThread         304 GET /stop (::1) 1.00ms
2013-07-06 01:41:15,384     INFO       MainThread         304 GET /cache/1373071236.712 (::1) 3.00ms

DO we need to enforce a timeout?

Original Comment By: Will Hart