Совокупные причины сбоя сегмента с помощью Aerospike
Я использую Apache 2.4 с PHP-FPM 7.0 на компьютере с Debian и расширением Aerospike версии 3.4.14
У меня есть набор со следующей структурой:
| ПК | значение | async_id | paxPrice | авиакомпании | аэропорты | depAirport
| endAirport | takeDep | takeRet | LandDep | LandRet | FlightChange |
connectionTime | moxedAirlines | ноги |
А вот пример записи:
«m_0a5c24dcf0e461127060839526d366ab_Sabre_126» |
«А: 5: {s: 5:» цена «; а: 14: {s: 5:» Общее «г: 11663,839999999998; s: 11:» pricePerPax «; д: 1943,97; s: 8:» totalflt» ; d: 11663,839999999998; s: 9: «baseprice»; д: 10459,799999999997; s: 3: «налог»; д: 1024,04; s: 10: «servicefee»; я: 180; s: 11: «markupprice»; д : 5409,9000000000005; s: 11: «агент
| «0a5c24dcf0e461127060839526d366ab» | 1943,97 | СПИСОК (‘[«OS», «BA»]’)
| СПИСОК (‘[]’) | «SOF» | СПИСОК (‘[]’) | «11:05» | «11:05» | «15:50» |
«15:50» | 2 | 250 | 1 | 1 |
Так что, в основном, в значении bin у меня есть сериализованный объект и массивы / strings / ints в других ячейках.
В этом наборе 196 строк / записей.
Я пытаюсь получить список всех строк, в которых я указал async_id, и упорядочить их по paxPrice, поэтому я создал следующий lua:
function filter_order(element,param)
local function mapper(rec)
local element = map()
element["paxPrice"] = rec["paxPrice"]
element["async_id"] = rec["async_id"]
return element
end
local function accumulate(currentList, nextElement)
local paxPrice = nextElement["paxPrice"]
info("current:"..tostring(currentList).." next:"..tostring(nextElement))
if currentList[paxPrice] == nil then
currentList[paxPrice] = list()
end
list.append(currentList[paxPrice], nextElement)
return currentList
end
local function mymerge(a,b)
return list.merge(a,b)
end
local function reducer(this,that)
return map.merge(this,that,mymerge)
end
return element:map(mapper):aggregate(map{}, accumulate):reduce(reducer)
end
Затем выполните этот скрипт в php (где $ this-> cache ссылается на кеш aerospike):
$where = \Aerospike::predicateEquals("search_async_id",'0a5c24dcf0e461127060839526d366ab');
$result=[];
$this->cache->getDB()->aggregate($this->cache->getNamespace(),'search_results',$where,'filter_order','filter_order',["5"], $result);
var_dump($result);
exit();
Однако это приводит к ошибке 500 в браузере и следующему в журнале apache:
[Mon May 29 09:22:20.018040 2017] [fastcgi:error] [pid 7533:tid 140333425817344] (104)Connection reset by peer: [client 95.169.214.202:64970] FastCGI: comm with server "/usr/lib/cgi-bin/php7.0" aborted: read failed
[Mon May 29 09:22:20.018181 2017] [fastcgi:error] [pid 7533:tid 140333425817344] [client 95.169.214.202:64970] FastCGI: incomplete headers (0 bytes) received from server "/usr/lib/cgi-bin/php7.0
То, что я вижу на каждом выполнении в php-fpm.log:
[29-May-2017 09:19:22] WARNING: [pool www] child 8923 exited on signal 11 (SIGSEGV) after 949.301664 seconds from start
[29-May-2017 09:19:22] NOTICE: [pool www] child 9081 started
В aerospike.log я получаю это, что заставляет меня думать, что сервис работает правильно:
........
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f6277bdcfe0) name(0x40dd2208)[async_id] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:225) [ENTER] Opening record key:<Digest>:0xe3ff8ebe962d161a9e90535ff69ca29026100d6b
May 29 2017 09:56:43 GMT: INFO (aggr): (/opt/aerospike/usr/udf/lua/filter_order.lua:11) current:{} next:{"paxPrice":1831.88, "async_id":"0a5c24dcf0e461127060839526d366ab"}
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:84) [ENTER] Opening record key:<Digest>:0xe3ff8ebe962d161a9e90535ff69ca29026100d6b
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:286) [ENTER] Closing record key:<Digest>:0xd00f17e1eb4d4fa11e9aac61dd3cf6fd53b5dbda
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:462) [ENTER] NumUpdates(2)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253e18220) name(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f62773dbfe0) name(0x4149d0c0)[paxPrice] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:225) [ENTER] Opening record key:<Digest>:0xf47f9a9d562f0c408346d78326580d75bf75d2f5
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253e18220) name(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:84) [ENTER] Opening record key:<Digest>:0xf47f9a9d562f0c408346d78326580d75bf75d2f5
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253c0ef40) name(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f6276bdafe0) name(0x416220c0)[paxPrice] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253c0ef40) name(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f6276bdafe0) name(0x416221d0)[async_id] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f62773dbfe0) name(0x4149d1d0)[async_id] dirty(0)
May 29 2017 09:56:43 GMT: INFO (aggr): (/opt/aerospike/usr/udf/lua/filter_order.lua:11) current:{} next:{"paxPrice":514.27, "async_id":"0a5c24dcf0e461127060839526d366ab"}
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:286) [ENTER] Closing record key:<Digest>:0xf47f9a9d562f0c408346d78326580d75bf75d2f5
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:462) [ENTER] NumUpdates(2)
May 29 2017 09:56:43 GMT: INFO (aggr): (/opt/aerospike/usr/udf/lua/filter_order.lua:11) current:{} next:{"paxPrice":517.85, "async_id":"0a5c24dcf0e461127060839526d366ab"}
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:286) [ENTER] Closing record key:<Digest>:0xe3ff8ebe962d161a9e90535ff69ca29026100d6b
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:462) [ENTER] NumUpdates(2)
May 29 2017 09:56:43 GMT: INFO (scan): (scan.c:1098) finished aggregation scan job 11754624473865748080 (0)
May 29 2017 09:56:44 GMT: DEBUG (demarshal): (thr_demarshal.c:646) running on CPU 3
May 29 2017 09:56:44 GMT: DEBUG (paxos): (paxos.c:2005) PAXOS message with ID 13 received from node bb9b25b63000056
May 29 2017 09:56:44 GMT: DEBUG (paxos): (paxos.c:2716) unwrapped | received paxos message from node bb9b25b63000056 command RETRANSMIT_CHECK (13)
May 29 2017 09:56:44 GMT: DEBUG (sindex): (secondary_index.c:1507) Index mytedev:search_paxPrice in 2 state Reserved to reference count 2 < 2 at base/thr_sindex.c:329
May 29 2017 09:56:44 GMT: DEBUG (demarshal): (thr_demarshal.c:175) Reaping FD 29 as requested
May 29 2017 09:56:44 GMT: DEBUG (cf:socket): (socket.c:1185) Closing FD 29
May 29 2017 09:56:44 GMT: DEBUG (demarshal): (thr_demarshal.c:175) Reaping FD 30 as requested
May 29 2017 09:56:44 GMT: DEBUG (cf:socket): (socket.c:1185) Closing FD 30
May 29 2017 09:56:45 GMT: DEBUG (demarshal): (thr_demarshal.c:646) running on CPU 3
May 29 2017 09:56:45 GMT: DEBUG (sindex): (secondary_index.c:1507) Index mytedev:search_paxPrice in 2 state Reserved to reference count 2 < 2 at base/thr_sindex.c:329
May 29 2017 09:56:46 GMT: DEBUG (demarshal): (thr_demarshal.c:646) running on CPU 3
May 29 2017 09:56:46 GMT: DEBUG (paxos): (paxos.c:2005) PAXOS message with ID 13 received from node bb9b25b63000056
May 29 2017 09:56:46 GMT: DEBUG (paxos): (paxos.c:2716) unwrapped | received paxos message from node bb9b25b63000056 command RETRANSMIT_CHECK (13)
Итак, я пошел, чтобы проверить, что случилось с ошибкой, и dmesg дает мне это:
.....
[4222171.116554] php-fpm7.0[8888]: segfault at 0 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4222172.079863] php-fpm7.0[8906]: segfault at 1f ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4222399.581538] php-fpm7.0[8929]: segfault at 0 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4222879.548465] php-fpm7.0[9038]: segfault at 20 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4223089.161566] php-fpm7.0[9063]: segfault at 0 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4223121.381333] traps: php-fpm7.0[9010] general protection ip:7fc4ab1e1c3a sp:7fc49cb25708 error:0 in libc-2.19.so[7fc4ab160000+1a1000]
[4223298.943340] php-fpm7.0[9116]: segfault at 20 ip 00007f9561724c3a sp 00007f9552f25708 error 4 in libc-2.19.so[7f95616a3000+1a1000]
[4225362.832272] php-fpm7.0[9288]: segfault at 0 ip 00007f9561724c3a sp 00007f9552f25708 error 4 in libc-2.19.so[7f95616a3000+1a1000]
Основной дамп и GDB показывает это:
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `php-fpm: pool www '.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00007f9561724c3a in strlen () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) t
[Current thread is 1 (Thread 0x7f9552f26700 (LWP 9116))]
(gdb) bt
#0 0x00007f9561724c3a in strlen () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x00007f95600246f4 in ADD_MAP_ASSOC_LIST (as=0x7f9560c73c60, key=0x7f954403ff70, value=0x7f953c025460, array=0x7f9552f25860, err=0x7ffd4e23fe30)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1274
#2 0x00007f9560025854 in AS_MAP_GET_CALLBACK (key=0x7f954403ff70, value=0x7f953c025460, array=0x7f9552f25860)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1425
#3 0x00007f9560076510 in as_hashmap_foreach (map=0x7f9544035f50, callback=0x7f9560025367 <AS_MAP_GET_CALLBACK>, udata=0x7f9552f25860) at src/main/aerospike/as_hashmap.c:498
#4 0x00007f95600213c2 in as_map_foreach (map=0x7f9544035f50, callback=0x7f9560025367 <AS_MAP_GET_CALLBACK>, udata=0x7f9552f25860)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/../aerospike-client-c/include/aerospike/as_map.h:357
#5 0x00007f95600244d5 in ADD_LIST_APPEND_MAP (as=0x7f9560c73c60, key=0x0, value=0x7f9544035f50, array=0x7ffd4e177b80, err=0x7ffd4e23fe30)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1223
#6 0x00007f9560025ed1 in AS_AGGREGATE_GET (as=0x7f9560c73c60, key=0x0, value=0x7f9544035f50, array=0x7ffd4e177b80)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1549
#7 0x00007f956001e66e in aerospike_helper_aggregate_callback (val_p=0x7f9544035f50, udata_p=0x7ffd4e177b80) at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_helper.c:755
#8 0x00007f956005c747 in as_output_stream_write (s=<optimized out>, val=0x7f9544035f50) at src/main/aerospike/aerospike_query.c:182
#9 0x00007f9560083977 in as_stream_write (value=<optimized out>, stream=0x7f9552f25e60) at ../../modules/common/target/Linux-x86_64/include/aerospike/as_stream.h:231
#10 mod_lua_stream_write (l=0x7f95440008c0) at src/main/mod_lua_stream.c:113
#11 0x00007f9560088c14 in luaD_precall () from /usr/lib/php/20151012/aerospike.so
#12 0x00007f9560097f38 in luaV_execute () from /usr/lib/php/20151012/aerospike.so
#13 0x00007f956008906d in luaD_call () from /usr/lib/php/20151012/aerospike.so
#14 0x00007f95600882ea in luaD_rawrunprotected () from /usr/lib/php/20151012/aerospike.so
#15 0x00007f956008921f in luaD_pcall () from /usr/lib/php/20151012/aerospike.so
#16 0x00007f9560085291 in lua_pcall () from /usr/lib/php/20151012/aerospike.so
#17 0x00007f956007dd75 in apply (l=l@entry=0x7f95440008c0, err=err@entry=25, argc=argc@entry=5, res=res@entry=0x7f9552f25e80, is_stream=is_stream@entry=true, udf_ctx=0x7f9552f25e40)
at src/main/mod_lua.c:858
#18 0x00007f956007e844 in apply_stream (m=<optimized out>, udf_ctx=0x7f9552f25e40, filename=0x7ffd4e177c39 "filter_order", function=0x7ffd4e177c79 "filter_order", istream=0x7ffd4e177a10,
args=<optimized out>, ostream=0x7f9552f25e60, res=0x7f9552f25e80) at src/main/mod_lua.c:1289
#19 0x00007f956005c8d3 in as_query_aggregate (data=0x7ffd4e177a30) at src/main/aerospike/aerospike_query.c:884
#20 0x00007f9560078264 in as_thread_worker (data=0x7f9564d99b08) at src/main/aerospike/as_thread_pool.c:52
#21 0x00007f9561a56064 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#22 0x00007f956178b62d in clone () from /lib/x86_64-linux-gnu/libc.so.6
(gdb)
Я думаю, что это проблема клиента аэроспайк, но я могу ошибаться. Есть идеи по этому поводу?
Решение
Проблема, как описано в https://github.com/aerospike/aerospike-client-php/issues/142 Оказалось, что ключ массива был (иногда) переменной с плавающей запятой, что вызвало ошибку сегмента.
Таким образом, проблема была на самом деле в файле lua, который должен гласить:
local paxPrice = tostring(nextElement["paxPrice"])
Другие решения
Я использую Apache 2.4 с PHP-FPM 7.0 на компьютере с Debian и расширением Aerospike версии 3.4.14
У меня есть набор со следующей структурой:
| ПК | значение | async_id | paxPrice | авиакомпании | аэропорты | depAirport
| endAirport | takeDep | takeRet | LandDep | LandRet | FlightChange |
connectionTime | moxedAirlines | ноги |
А вот пример записи:
«m_0a5c24dcf0e461127060839526d366ab_Sabre_126» |
«А: 5: {s: 5:» цена «; а: 14: {s: 5:» Общее «г: 11663,839999999998; s: 11:» pricePerPax «; д: 1943,97; s: 8:» totalflt» ; d: 11663,839999999998; s: 9: «baseprice»; д: 10459,799999999997; s: 3: «налог»; д: 1024,04; s: 10: «servicefee»; я: 180; s: 11: «markupprice»; д : 5409,9000000000005; s: 11: «агент
| «0a5c24dcf0e461127060839526d366ab» | 1943,97 | СПИСОК (‘[«OS», «BA»]’)
| СПИСОК (‘[]’) | «SOF» | СПИСОК (‘[]’) | «11:05» | «11:05» | «15:50» |
«15:50» | 2 | 250 | 1 | 1 |
Так что, в основном, в значении bin у меня есть сериализованный объект и массивы / strings / ints в других ячейках.
В этом наборе 196 строк / записей.
Я пытаюсь получить список всех строк, в которых я указал async_id, и упорядочить их по paxPrice, поэтому я создал следующий lua:
function filter_order(element,param)
local function mapper(rec)
local element = map()
element["paxPrice"] = rec["paxPrice"]
element["async_id"] = rec["async_id"]
return element
end
local function accumulate(currentList, nextElement)
local paxPrice = nextElement["paxPrice"]
info("current:"..tostring(currentList).." next:"..tostring(nextElement))
if currentList[paxPrice] == nil then
currentList[paxPrice] = list()
end
list.append(currentList[paxPrice], nextElement)
return currentList
end
local function mymerge(a,b)
return list.merge(a,b)
end
local function reducer(this,that)
return map.merge(this,that,mymerge)
end
return element:map(mapper):aggregate(map{}, accumulate):reduce(reducer)
end
Затем выполните этот скрипт в php (где $ this-> cache ссылается на кеш aerospike):
$where = \Aerospike::predicateEquals("search_async_id",'0a5c24dcf0e461127060839526d366ab');
$result=[];
$this->cache->getDB()->aggregate($this->cache->getNamespace(),'search_results',$where,'filter_order','filter_order',["5"], $result);
var_dump($result);
exit();
Однако это приводит к ошибке 500 в браузере и следующему в журнале apache:
[Mon May 29 09:22:20.018040 2017] [fastcgi:error] [pid 7533:tid 140333425817344] (104)Connection reset by peer: [client 95.169.214.202:64970] FastCGI: comm with server "/usr/lib/cgi-bin/php7.0" aborted: read failed
[Mon May 29 09:22:20.018181 2017] [fastcgi:error] [pid 7533:tid 140333425817344] [client 95.169.214.202:64970] FastCGI: incomplete headers (0 bytes) received from server "/usr/lib/cgi-bin/php7.0
То, что я вижу на каждом выполнении в php-fpm.log:
[29-May-2017 09:19:22] WARNING: [pool www] child 8923 exited on signal 11 (SIGSEGV) after 949.301664 seconds from start
[29-May-2017 09:19:22] NOTICE: [pool www] child 9081 started
В aerospike.log я получаю это, что заставляет меня думать, что сервис работает правильно:
........
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f6277bdcfe0) name(0x40dd2208)[async_id] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:225) [ENTER] Opening record key:<Digest>:0xe3ff8ebe962d161a9e90535ff69ca29026100d6b
May 29 2017 09:56:43 GMT: INFO (aggr): (/opt/aerospike/usr/udf/lua/filter_order.lua:11) current:{} next:{"paxPrice":1831.88, "async_id":"0a5c24dcf0e461127060839526d366ab"}
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:84) [ENTER] Opening record key:<Digest>:0xe3ff8ebe962d161a9e90535ff69ca29026100d6b
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:286) [ENTER] Closing record key:<Digest>:0xd00f17e1eb4d4fa11e9aac61dd3cf6fd53b5dbda
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:462) [ENTER] NumUpdates(2)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253e18220) name(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f62773dbfe0) name(0x4149d0c0)[paxPrice] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:225) [ENTER] Opening record key:<Digest>:0xf47f9a9d562f0c408346d78326580d75bf75d2f5
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253e18220) name(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:84) [ENTER] Opening record key:<Digest>:0xf47f9a9d562f0c408346d78326580d75bf75d2f5
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253c0ef40) name(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(paxPrice)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f6276bdafe0) name(0x416220c0)[paxPrice] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:712) [ENTER] rec(0x7f6253c0ef40) name(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f6276bdafe0) name(0x416221d0)[async_id] dirty(0)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:445) [ENTER] BinName(async_id)
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:496) [ENTER] urecord(0x7f62773dbfe0) name(0x4149d1d0)[async_id] dirty(0)
May 29 2017 09:56:43 GMT: INFO (aggr): (/opt/aerospike/usr/udf/lua/filter_order.lua:11) current:{} next:{"paxPrice":514.27, "async_id":"0a5c24dcf0e461127060839526d366ab"}
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:286) [ENTER] Closing record key:<Digest>:0xf47f9a9d562f0c408346d78326580d75bf75d2f5
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:462) [ENTER] NumUpdates(2)
May 29 2017 09:56:43 GMT: INFO (aggr): (/opt/aerospike/usr/udf/lua/filter_order.lua:11) current:{} next:{"paxPrice":517.85, "async_id":"0a5c24dcf0e461127060839526d366ab"}
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:286) [ENTER] Closing record key:<Digest>:0xe3ff8ebe962d161a9e90535ff69ca29026100d6b
May 29 2017 09:56:43 GMT: DEBUG (udf): (udf_record.c:462) [ENTER] NumUpdates(2)
May 29 2017 09:56:43 GMT: INFO (scan): (scan.c:1098) finished aggregation scan job 11754624473865748080 (0)
May 29 2017 09:56:44 GMT: DEBUG (demarshal): (thr_demarshal.c:646) running on CPU 3
May 29 2017 09:56:44 GMT: DEBUG (paxos): (paxos.c:2005) PAXOS message with ID 13 received from node bb9b25b63000056
May 29 2017 09:56:44 GMT: DEBUG (paxos): (paxos.c:2716) unwrapped | received paxos message from node bb9b25b63000056 command RETRANSMIT_CHECK (13)
May 29 2017 09:56:44 GMT: DEBUG (sindex): (secondary_index.c:1507) Index mytedev:search_paxPrice in 2 state Reserved to reference count 2 < 2 at base/thr_sindex.c:329
May 29 2017 09:56:44 GMT: DEBUG (demarshal): (thr_demarshal.c:175) Reaping FD 29 as requested
May 29 2017 09:56:44 GMT: DEBUG (cf:socket): (socket.c:1185) Closing FD 29
May 29 2017 09:56:44 GMT: DEBUG (demarshal): (thr_demarshal.c:175) Reaping FD 30 as requested
May 29 2017 09:56:44 GMT: DEBUG (cf:socket): (socket.c:1185) Closing FD 30
May 29 2017 09:56:45 GMT: DEBUG (demarshal): (thr_demarshal.c:646) running on CPU 3
May 29 2017 09:56:45 GMT: DEBUG (sindex): (secondary_index.c:1507) Index mytedev:search_paxPrice in 2 state Reserved to reference count 2 < 2 at base/thr_sindex.c:329
May 29 2017 09:56:46 GMT: DEBUG (demarshal): (thr_demarshal.c:646) running on CPU 3
May 29 2017 09:56:46 GMT: DEBUG (paxos): (paxos.c:2005) PAXOS message with ID 13 received from node bb9b25b63000056
May 29 2017 09:56:46 GMT: DEBUG (paxos): (paxos.c:2716) unwrapped | received paxos message from node bb9b25b63000056 command RETRANSMIT_CHECK (13)
Итак, я пошел, чтобы проверить, что случилось с ошибкой, и dmesg дает мне это:
.....
[4222171.116554] php-fpm7.0[8888]: segfault at 0 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4222172.079863] php-fpm7.0[8906]: segfault at 1f ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4222399.581538] php-fpm7.0[8929]: segfault at 0 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4222879.548465] php-fpm7.0[9038]: segfault at 20 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4223089.161566] php-fpm7.0[9063]: segfault at 0 ip 00007fc4ab1e1c3a sp 00007fc49cb25708 error 4 in libc-2.19.so[7fc4ab160000+1a1000]
[4223121.381333] traps: php-fpm7.0[9010] general protection ip:7fc4ab1e1c3a sp:7fc49cb25708 error:0 in libc-2.19.so[7fc4ab160000+1a1000]
[4223298.943340] php-fpm7.0[9116]: segfault at 20 ip 00007f9561724c3a sp 00007f9552f25708 error 4 in libc-2.19.so[7f95616a3000+1a1000]
[4225362.832272] php-fpm7.0[9288]: segfault at 0 ip 00007f9561724c3a sp 00007f9552f25708 error 4 in libc-2.19.so[7f95616a3000+1a1000]
Основной дамп и GDB показывает это:
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `php-fpm: pool www '.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00007f9561724c3a in strlen () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) t
[Current thread is 1 (Thread 0x7f9552f26700 (LWP 9116))]
(gdb) bt
#0 0x00007f9561724c3a in strlen () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x00007f95600246f4 in ADD_MAP_ASSOC_LIST (as=0x7f9560c73c60, key=0x7f954403ff70, value=0x7f953c025460, array=0x7f9552f25860, err=0x7ffd4e23fe30)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1274
#2 0x00007f9560025854 in AS_MAP_GET_CALLBACK (key=0x7f954403ff70, value=0x7f953c025460, array=0x7f9552f25860)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1425
#3 0x00007f9560076510 in as_hashmap_foreach (map=0x7f9544035f50, callback=0x7f9560025367 <AS_MAP_GET_CALLBACK>, udata=0x7f9552f25860) at src/main/aerospike/as_hashmap.c:498
#4 0x00007f95600213c2 in as_map_foreach (map=0x7f9544035f50, callback=0x7f9560025367 <AS_MAP_GET_CALLBACK>, udata=0x7f9552f25860)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/../aerospike-client-c/include/aerospike/as_map.h:357
#5 0x00007f95600244d5 in ADD_LIST_APPEND_MAP (as=0x7f9560c73c60, key=0x0, value=0x7f9544035f50, array=0x7ffd4e177b80, err=0x7ffd4e23fe30)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1223
#6 0x00007f9560025ed1 in AS_AGGREGATE_GET (as=0x7f9560c73c60, key=0x0, value=0x7f9544035f50, array=0x7ffd4e177b80)
at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_transform.c:1549
#7 0x00007f956001e66e in aerospike_helper_aggregate_callback (val_p=0x7f9544035f50, udata_p=0x7ffd4e177b80) at /opt/vendor/aerospike/aerospike-client-php/src/aerospike/aerospike_helper.c:755
#8 0x00007f956005c747 in as_output_stream_write (s=<optimized out>, val=0x7f9544035f50) at src/main/aerospike/aerospike_query.c:182
#9 0x00007f9560083977 in as_stream_write (value=<optimized out>, stream=0x7f9552f25e60) at ../../modules/common/target/Linux-x86_64/include/aerospike/as_stream.h:231
#10 mod_lua_stream_write (l=0x7f95440008c0) at src/main/mod_lua_stream.c:113
#11 0x00007f9560088c14 in luaD_precall () from /usr/lib/php/20151012/aerospike.so
#12 0x00007f9560097f38 in luaV_execute () from /usr/lib/php/20151012/aerospike.so
#13 0x00007f956008906d in luaD_call () from /usr/lib/php/20151012/aerospike.so
#14 0x00007f95600882ea in luaD_rawrunprotected () from /usr/lib/php/20151012/aerospike.so
#15 0x00007f956008921f in luaD_pcall () from /usr/lib/php/20151012/aerospike.so
#16 0x00007f9560085291 in lua_pcall () from /usr/lib/php/20151012/aerospike.so
#17 0x00007f956007dd75 in apply (l=l@entry=0x7f95440008c0, err=err@entry=25, argc=argc@entry=5, res=res@entry=0x7f9552f25e80, is_stream=is_stream@entry=true, udf_ctx=0x7f9552f25e40)
at src/main/mod_lua.c:858
#18 0x00007f956007e844 in apply_stream (m=<optimized out>, udf_ctx=0x7f9552f25e40, filename=0x7ffd4e177c39 "filter_order", function=0x7ffd4e177c79 "filter_order", istream=0x7ffd4e177a10,
args=<optimized out>, ostream=0x7f9552f25e60, res=0x7f9552f25e80) at src/main/mod_lua.c:1289
#19 0x00007f956005c8d3 in as_query_aggregate (data=0x7ffd4e177a30) at src/main/aerospike/aerospike_query.c:884
#20 0x00007f9560078264 in as_thread_worker (data=0x7f9564d99b08) at src/main/aerospike/as_thread_pool.c:52
#21 0x00007f9561a56064 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#22 0x00007f956178b62d in clone () from /lib/x86_64-linux-gnu/libc.so.6
(gdb)
Я думаю, что это проблема клиента аэроспайк, но я могу ошибаться. Есть идеи по этому поводу?
Проблема, как описано в https://github.com/aerospike/aerospike-client-php/issues/142 Оказалось, что ключ массива был (иногда) переменной с плавающей запятой, что вызвало ошибку сегмента.
Таким образом, проблема была на самом деле в файле lua, который должен гласить:
local paxPrice = tostring(nextElement["paxPrice"])