digitalmethodsinitiative / dmi-tcat

Digital Methods Initiative - Twitter Capture and Analysis Toolset
Apache License 2.0
367 stars 114 forks source link

Capture stopping #302

Closed jamestripp closed 5 years ago

jamestripp commented 6 years ago

Good morning,

I'm running TCAT on Ubuntu 15:10. I have a bin running and suddenly it just stops. To restart the capture I need to run the dmitcat_track.php script for a few minutes and then the controller.php. I coudln't find anythign of use in either the controller.log or track.error.log.

Is this something that tends to happen? The tracking has stopped a few times this week.

Best,

James

dentoir commented 6 years ago

Hi @jamestripp

Not normally, perhaps this has to do with your network connectivity being interrupted. If your error logs are empty, it usually means the tracking script is hanging on I/O. How long have you been running this instance? Can you verify your system clock time is correct? Can you try to ping api.twitter.com for a while from your server and see if there is packet loss?

dentoir commented 6 years ago

Also don't forget to look at the other error logs, such as from Apache and MySQL.

jamestripp commented 6 years ago

Hi @dentoir

Thanks for your quick response. I've been running this instance over the past year and have only had this issue over the past month.

Pinging api.twitter.com shows 0% packet loss on a few hundred packets. The MySQL and Apache2 error logs show nothing out of the ordinary.

I'm not sure what to do next.

Thanks again,

James

dentoir commented 6 years ago

Hi @jamestripp

First, do you see messages in dmesg (as root) as this may indicate problems as well?

Otherwise, this is somewhat tricky and requires command-line tools, but what I would try next are the following steps. I'm not sure what (Linux) OS you are on though?

Install the strace package.

Whenever track is running again (started via controller), mark it's PID (with the ps -aux command) and, as root, issue the following command strace -p PID where PID is the number of the process. You will see a lot of messages indicating what the process is doing in terms of system calls. You will want to start the strace command inside a screen (with screen) so you can detach from it. Once the capture has stopped re-attach to this screen and report the last hundred lines back. This may hint to what went wrong.

Alternatively, you can just wait till the capture is hanging and then do the strace -p PID. Now, I'm assuming the track process is still alive, right? I'm interested in whether it is still outputting data or not. I've experienced a deep hanging state when I was tunneling the outgoing TCP/IP connection and the network connection was temporarily dropped. The script went unkillable and strace gave zero output.

jamestripp commented 6 years ago

Hi @dentoir

Nothing obvious in dmesg. I'm running strace and will attach the output when the data collection stops. Hmm, I'm not sure if the process is still alive or not.

Shall report back. Thanks for your help!

Best,

James

jamestripp commented 6 years ago

Hi @dentoir ,

The data capture went down last night. The output of the trace command (what was left in the buffer from screen) is attached. strace.txt

When I logged back in a new process called controller.php had started. Running strace on this process displayed 'wait4(processid,' where processid is was an ID different from the individual. Then the process died for some reason and showed a similiar output as the other process.

I'm not entirely sure what to do next. I'll restart controller.php to get continue collecting the data. Though I'm unsure how to interpret the output of strace.

Best,

James

dentoir commented 6 years ago

Hi @jamestripp

Controller.php is started every minute by cron to start the actual tracking process called dmitcat_track.php. So the controller process dying is expected behavior. You shouldn't normally start the tracking process by hand because the controller may interfere with it. Did you do a manual install or did you use the auto installer?

Can you verify the posix and pcntl modules are loaded in PHP? They should be listed in the output of php -m on the command-line. If not, that might by a problem.

From the strace it appears track is trying to quit, but apparently fails. You say track.error.log is not relevant? Can you still display the content right before a restart?

What I would suggest now is, as root, removing all PID files and content under proc/ ; making sure that directory is writable to the tracking user (perhaps just use the command: chmod 777 proc), kill all TCAT processes and wait for the controller (via cron) to start your tracking process. If the tracking process then hangs again this issue is very problematic to debug and most likely network related.

Best,

Emile

jamestripp commented 6 years ago

Hi @dentoir ,

The PHP modules are there and thanks for pointing that out about controller.php.

The track.error.log reports and error starting '2018-01-24 18:21:59 stream stopped - error tmhOAuth::__set_state'. I misread the log before. I understand this is something to do with authenticating the api query with twitter, but I'm not sure the exact error and how to fix it. Do you have any ideas?

I've also removed the PID files under proc/ and checked that it is writable by the user, etc.

Best,

James

dentoir commented 6 years ago

Hi @jamestripp

Is that the only line in track.error.log before the restart?

jamestripp commented 6 years ago

Hi @dentoir

Capture stopped again last night. The track.error.log output is below with query and key information removed.

I'm guessing Twitter throws up an authentication error, capture stops, then works again when I start the script. How odd! If this is an authentication issue then I could regenerate the API keys and see if that solves the issue.

Does this appear to you to be purely an authentication error?

Thanks and apologies for being slow to respond,

James

018-02-14 19:36:40 stream stopped - error tmhOAuth::__set_state(array( 'response' => array ( 'raw' => 'HTTP/1.1 200 OK^M connection: close^M content-Encoding: gzip^M content-type: application/json^M date: Sun, 11 Feb 2018 09:49:31 GMT^M server: tsa^M transfer-encoding: chunked^M x-connection-hash: 8761963c61a5f2578fd65ac0034aaa64^M ^M 1', 'content-length' => 0, 'headers' => array ( 'HTTP/1.1 200 OK' => '', 'connection' => 'close', 'content-Encoding' => 'gzip', 'content-type' => 'application/json', 'date' => 'Sun, 11 Feb 2018 09:49:31 GMT', 'server' => 'tsa', 'transfer-encoding' => 'chunked', 'x-connection-hash' => '8761963c61a5f2578fd65ac0034aaa64', '' => '', ), 'code' => 200, 'response' => true, 'info' => array ( 'url' => 'https://stream.twitter.com/1.1/statuses/filter.json', 'content_type' => 'application/json', 'http_code' => 200, 'header_size' => 225, 'request_size' => 858, 'filetime' => -1, 'ssl_verify_result' => 0, 'redirect_count' => 0, 'total_time' => 294428.79168800003, 'namelookup_time' => 0.012212000000000001, 'connect_time' => 0.11483299999999996, 'pretransfer_time' => 0.32770699999999997, 'size_upload' => 282, 'size_download' => 30639594, 'speed_download' => 104, 'speed_upload' => 0, 'download_content_length' => -1, 'upload_content_length' => 282, 'starttransfer_time' => 0.88741499999999995, 'redirect_time' => 0, 'redirect_url' => '', 'primary_ip' => '199.16.156.217', 'certinfo' => array ( ), 'primary_port' => 443, 'local_ip' => ‘XX’, 'local_port' => 53776, 'request_header' => 'POST /1.1/statuses/filter.json HTTP/1.1^M Host: stream.twitter.com^M User-Agent: tmhOAuth 0.8.3+SSL - //github.com/themattharris/tmhOAuth^M Accept: /^M Accept-Encoding: deflate, gzip^M Authorization: OAuth oauth_consumer_key="XX”, oauth_nonce=“XX”, oauth_signature=“XX”, oauth_signature_method="HMAC-SHA1", oauth_timestamp="1518342571", oauth_token=“XX”, oauth_version="1.0"^M Content-Length: 282^M Content-Type: application/x-www-form-urlencoded^M ^M ', ), 'error' => '', 'errno' => 0, ), 'buffer' => '', 'config' => array ( 'user_agent' => 'tmhOAuth 0.8.3+SSL - //github.com/themattharris/tmhOAuth', 'host' => 'stream.twitter.com', 'consumer_key' => ‘XX’, 'consumer_secret' => ‘XX’, 'token' => ‘XX’, 'secret' => ‘XX’, 'bearer' => '', 'oauth_version' => '1.0', 'oauth_signature_method' => 'HMAC-SHA1', 'curl_http_version' => 2, 'curl_connecttimeout' => 30, 'curl_timeout' => 10, 'curl_ssl_verifyhost' => 2, 'curl_ssl_verifypeer' => true, 'use_ssl' => true, 'curl_cainfo' => '/var/www/dmi-tcat/capture/common/tmhOAuth/cacert.pem', 'curl_capath' => '/var/www/dmi-tcat/capture/common/tmhOAuth', 'curl_followlocation' => false, 'curl_proxy' => false, 'curl_proxyuserpwd' => false, 'curl_encoding' => '', 'is_streaming' => true, 'streaming_eol' => '^M ', 'streaming_metrics_interval' => 10, 'as_header' => true, 'force_nonce' => false, 'force_timestamp' => false, 'streaming_callback' => 'tracker_streamCallback', ), 'request_settings' => array ( 'params' => array ( 'track' => ‘XX’, ), 'headers' => array ( 'Host' => 'stream.twitter.com', 'Authorization' => 'OAuth oauth_consumer_key=“XX”, oauth_nonce=“XX”, oauth_signature=“XX”, oauth_signature_method="HMAC-SHA1", oauth_timestamp="1518342571", oauth_token=“XX”, oauth_version="1.0"', ), 'with_user' => true, 'multipart' => false, 'method' => 'POST', 'without_bearer' => false, 'url' => 'https://stream.twitter.com/1.1/statuses/filter.json', 'oauth1_params' => array ( 'oauth_consumer_key' => ‘XX’, 'oauth_nonce' => ‘XX’, 'oauth_signature' => ‘XX’, 'oauth_signature_method' => 'HMAC-SHA1', 'oauth_timestamp' => '1518342571', 'oauth_token' => ‘XX’, 'oauth_version' => '1.0', ), 'prepared_params' => array ( 'track' => ), 'basestring_params' => ‘”’, 'postfields' => '', 'basestring' => '), 'metrics' => array ( 'start' => 1518342571, 'interval_start' => 1518636989, 'messages' => 48283, 'last_messages' => 48280, 'bytes' => 102148024, 'last_bytes' => 102145484, 'mps' => 0.20000000000000001, 'bps' => 880.70000000000005, ), )) 2018-02-14 19:36:40 processing buffer before exit

ErikBorra commented 6 years ago

Is your system clock time correct? The Twitter API denies requests from machines which have an improperly configured clock. Check the date with the date command. To sync the server time automatically, install a tool like ntp to keep your system clock synchronized.

jamestripp commented 6 years ago

Hi Eric,

Thanks for replying.

It looks like my time is correct.

james@x:/var/www/dmi-tcat/capture/stream$ timedatectl Local time: Thu 2018-02-15 13:28:34 GMT Universal time: Thu 2018-02-15 13:28:34 UTC RTC time: Thu 2018-02-15 13:28:34 Time zone: Europe/London (GMT, +0000) Network time on: yes NTP synchronized: yes RTC in local TZ: no

jamestripp commented 6 years ago

Hi everyone,

The error is still occurring. I had a brand new TCAT install on ubuntu 16 and an older install on ubuntu 15 stop collecting on Friday due to the same error. Both happened at the same time. Does this sound like a Twitter or Authentication library issue? The network team have checked and there's been nothing unusual on their end.

Best,

James

dentoir commented 5 years ago

I'm closing this issue, I can't debug it. I assume this is network related.