Ian Babrou created THRIFT-2611:
----------------------------------
Summary: Thrift php bindings hang up
Key: THRIFT-2611
URL: https://issues.apache.org/jira/browse/THRIFT-2611
Project: Thrift
Issue Type: Bug
Components: PHP - Library
Environment: Linux 3.3.1, php-5.3.8-pl0-gentoo
Reporter: Ian Babrou
Stracing php process that eats 100% cpu showed the next pattern:
poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 1 ([{fd=4,
revents=POLLIN|POLLERR|POLLHUP}])
recvfrom(4, "", 1, MSG_PEEK, NULL, NULL) = 0
select(5, [4], [], [], {0, 20000}) = 1 (in [4], left {0, 19999})
recvfrom(4, "", 4, 0, NULL, NULL) = 0
poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 1 ([{fd=4,
revents=POLLIN|POLLERR|POLLHUP}])
recvfrom(4, "", 1, MSG_PEEK, NULL, NULL) = 0
select(5, [4], [], [], {0, 20000}) = 1 (in [4], left {0, 19999})
recvfrom(4, "", 4, 0, NULL, NULL) = 0
poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 1 ([{fd=4,
revents=POLLIN|POLLERR|POLLHUP}])
recvfrom(4, "", 1, MSG_PEEK, NULL, NULL) = 0
select(5, [4], [], [], {0, 20000}) = 1 (in [4], left {0, 19999})
recvfrom(4, "", 4, 0, NULL, NULL) = 0
poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 1 ([{fd=4,
revents=POLLIN|POLLERR|POLLHUP}])
recvfrom(4, "", 1, MSG_PEEK, NULL, NULL) = 0
select(5, [4], [], [], {0, 20000}) = 1 (in [4], left {0, 19999})
recvfrom(4, "", 4, 0, NULL, NULL) = 0
Attaching gdb made this picture more clear:
(gdb) dump_bt executor_globals.current_execute_data
[0x259ef3c8] read()
/project-path/vendor/thrift/lib/Thrift/Transport/TTransport.php:74
[0x259ef110] readAll()
/project-path/vendor/thrift/lib/Thrift/Transport/TFramedTransport.php:139
[0x259eeb78] readFrame()
/project-path/vendor/thrift/lib/Thrift/Transport/TFramedTransport.php:106
[0x259ee8e8] read()
/project-path/vendor/thrift/lib/Thrift/Transport/TTransport.php:74
[0x259ee608] readAll()
/project-path/vendor/thrift/lib/Thrift/Protocol/TBinaryProtocol.php:305
[0x259ede70] readI32()
/project-path/vendor/thrift/lib/Thrift/Protocol/TBinaryProtocol.php:197
[0x259ed5a0] readMessageBegin()
/project-path/vendor/thrift/packages/Scribe/Thrift/scribe.php:61
[0x259ed450] recv_Log()
/project-path/vendor/thrift/packages/Scribe/Thrift/scribe.php:30
[0x259ecfa8] Log() /project-path/src/Framework/Logger/ScribeHandler.php:126
[0x259ecc20] write()
/project-path/vendor/monolog/monolog/src/Monolog/Handler/AbstractProcessingHandler.php:37
[0x259ec070] handle()
/project-path/vendor/monolog/monolog/src/Monolog/Logger.php:264
[0x259ebef8] addRecord()
/project-path/vendor/monolog/monolog/src/Monolog/Logger.php:485
[0x259eabe0] warn() /project-path/lib/Cron/CronManager.php:419
[0x259ea2a0] update()
/project-path/src/Topface/SortedSet/Script/ProcessorCronScript.php:80
[0x259e9c20] run()
/project-path/src/Topface/NewDispatcher/NewScriptDispatcher.php:80
[0x259e97e0] dispatch() /project-path/lib/Application.php:359
[0x259e41b0] run() /project-path/config/run.php:268
[0x259e4050] ??? /project-path/bin/cron:10
Lsof on process with the same behavior and problem fd showed:
php 25612 www 16u sock 0,5 0t0 4049585261 can't identify protocol
Looks like php does not expose error (POLLERR is there), and allows to read
empty buffer what thrift happily does. EOF doesn't happen and cpu is wasted in
infinite cycle.
--
This message was sent by Atlassian JIRA
(v6.2#6252)