storage出现大量response status 17 log

[GoogleCodeExporter]

Usage: pstack <process-id>
[root@172-1-4-96 fastdfstest]# pstack  25270
Thread 11 (Thread 0x4177e940 (LWP 25271)):
#0  0x000000330bad4d98 in epoll_wait () from /lib64/libc.so.6
#1  0x000000000041aec3 in ioevent_poll ()
#2  0x000000000041bfb6 in ioevent_loop ()
#3  0x000000000043076f in work_thread_entrance ()
#4  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#5  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 10 (Thread 0x417ff940 (LWP 25272)):
#0  0x000000330bad4d98 in epoll_wait () from /lib64/libc.so.6
#1  0x000000000041aec3 in ioevent_poll ()
#2  0x000000000041bfb6 in ioevent_loop ()
#3  0x000000000043076f in work_thread_entrance ()
#4  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#5  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 9 (Thread 0x41880940 (LWP 25273)):
#0  0x000000330bad4d98 in epoll_wait () from /lib64/libc.so.6
#1  0x000000000041aec3 in ioevent_poll ()
#2  0x000000000041bfb6 in ioevent_loop ()
#3  0x000000000043076f in work_thread_entrance ()
#4  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#5  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 8 (Thread 0x4190f940 (LWP 25274)):
#0  0x000000330bad4d98 in epoll_wait () from /lib64/libc.so.6
#1  0x000000000041aec3 in ioevent_poll ()
#2  0x000000000041bfb6 in ioevent_loop ()
#3  0x000000000043076f in work_thread_entrance ()
#4  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#5  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 7 (Thread 0x41990940 (LWP 25275)):
#0  0x000000330bad4d98 in epoll_wait () from /lib64/libc.so.6
#1  0x000000000041aec3 in ioevent_poll ()
#2  0x000000000041bfb6 in ioevent_loop ()
#3  0x000000000043076f in work_thread_entrance ()
#4  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#5  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 6 (Thread 0x41a11940 (LWP 25276)):
#0  0x000000330ba9a901 in nanosleep () from /lib64/libc.so.6
#1  0x000000330ba9a724 in sleep () from /lib64/libc.so.6
#2  0x0000000000420fb1 in tracker_report_thread_entrance ()
#3  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#4  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 5 (Thread 0x41e39940 (LWP 25277)):
#0  0x000000330ba9a901 in nanosleep () from /lib64/libc.so.6
#1  0x000000330ba9a724 in sleep () from /lib64/libc.so.6
#2  0x0000000000417536 in sched_thread_entrance ()
#3  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#4  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 4 (Thread 0x41eba940 (LWP 25278)):
#0  0x000000330c20af59 in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#1  0x0000000000437800 in dio_thread_entrance ()
#2  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#3  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 3 (Thread 0x41f3b940 (LWP 25279)):
#0  0x000000330c20af59 in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#1  0x0000000000437800 in dio_thread_entrance ()
#2  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#3  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 2 (Thread 0x41fbc940 (LWP 25280)):
#0  0x000000330bacbab6 in poll () from /lib64/libc.so.6
#1  0x000000000041615a in tcprecvdata_nb_ex ()
#2  0x000000000041d795 in fdfs_recv_header ()
#3  0x000000000041d9f1 in fdfs_recv_response ()
#4  0x000000000043177b in storage_sync_modify_file ()
#5  0x00000000004344ae in storage_sync_thread_entrance ()
#6  0x000000330c20677d in start_thread () from /lib64/libpthread.so.0
#7  0x000000330bad49ad in clone () from /lib64/libc.so.6
Thread 1 (Thread 0x2b361cfcc060 (LWP 25270)):
#0  0x000000330c20dc0b in accept () from /lib64/libpthread.so.0
#1  0x000000000043006b in accept_thread_entrance ()
#2  0x000000000043031b in storage_accept_loop ()
#3  0x000000000040c62c in main ()

两个 storage log出现大量
[2014-04-25 16:43:30] ERROR - file: tracker_proto.c, line: 48, server: 
172.1.2.102:23000, response status 17 != 0

fastdfs_tracker_query_storage_store 无法获取storage文件信息

这会儿上传文件成功后获取文件信息
info: {
source_id: 0
create_timestamp: 16934483
file_size: 46774272
source_ip_addr: "0.77.122.172"//没见过的ip
crc32: 779812864

}

[root@172-1-4-96 fastdfstest]# strace -p 25270
Process 25270 attached - interrupt to quit
accept(5,  <unfinished ...> 一直卡在这里
Process 25270 detached
[root@172-1-4-96 fastdfstest]# 

tracker的log
[2014-04-25 16:41:53] INFO - FastDFS v5.01, base_path=/home/yuqing/fastdfs, 
run_by_group=, run_by_user=, connect_timeout=30s, network_timeout=60s, 
port=2122, bind_addr=, max_connections=256, accept_threads=1, work_threads=4, 
store_lookup=2, store_group=, store_server=0, store_path=0, 
reserved_storage_space=10.00%, download_server=0, allow_ip_count=-1, 
sync_log_buff_interval=10s, check_active_interval=120s, thread_stack_size=64 
KB, storage_ip_changed_auto_adjust=1, storage_sync_file_max_delay=86400s, 
storage_sync_file_max_time=300s, use_trunk_file=0, slot_min_size=256, 
slot_max_size=16 MB, trunk_file_size=64 MB, trunk_create_file_advance=0, 
trunk_create_file_time_base=02:00, trunk_create_file_interval=86400, 
trunk_create_file_space_threshold=20 GB, trunk_init_check_occupying=0, 
trunk_init_reload_from_binlog=0, trunk_compress_binlog_min_interval=0, 
use_storage_id=0, id_type_in_filename=ip, storage_id_count=0, 
rotate_error_log=0, error_log_rotate_time=00:00, rotate_error_log_size=0, 
store_slave_file_use_link=0, use_connection_pool=0, 
g_connection_pool_max_idle_time=3600s
[2014-04-25 16:41:53] INFO - local_host_ip_count: 2,  127.0.0.1  172.1.4.96
[2014-04-25 16:42:13] INFO - file: tracker_relationship.c, line: 383, selecting 
leader...
[2014-04-25 16:42:13] INFO - file: tracker_relationship.c, line: 401, I am the 
new tracker leader 172.1.4.96:2122

-----------------产生以上原因使用的脚本--跑了12个进程
$starttime = time();
$totalcount = 0;
$success_count = 0;
$del_count = 0;

while(true)
{
        $totalcount++;
        $info = FastFile::append_file_content($totalcount."\r\n","group1","M00/00/15/rAECZlNXcQGEdk0-AAAAANJEtCU128.txt");
        if (!$info) {
            var_dump(FastFile::getError());
        }else{
                $success_count ++;
                //$res = FastFile::delete_file($info["group_name"], $info["filename"]);
                //if($res)
                //{
                //      $del_count ++;
                //}
        }
        if($totalcount % 100==0)
        {
                echo "cost:". (time() - $starttime);
                echo " total:".$totalcount." success:".$success_count." del:".$del_count." \r\n";
        }
        if($totalcount >= 20000000)break;
}
echo "--------------------------------------------------------\r\n";
echo "cost:". (time() - $starttime);
echo " total:".$totalcount." success:".$success_count." \r\n";

//附加的lib
 public static function append_file_content($content, $group_name, $remote_filename)
    {
        if (!self::$tracker || !self::$storage) {
            if (!self::init()) {
                return false;
            }
        }
        return fastdfs_storage_append_by_filebuff($content, $group_name, $remote_filename, self::$tracker, self::$storage);
    }

public function init()
    {
        //获取资源查找器的链接信息
        self::$tracker = fastdfs_tracker_get_connection();
        if (!fastdfs_active_test(self::$tracker)) {
            return false;
        }

        //获取存储服务器
        self::$storage = fastdfs_tracker_query_storage_store();
        if (!self::$storage) {
            return false;
        }
        return true;
    }

Original issue reported on code.google.com by xcl3...@gmail.com on 25 Apr 2014 at 9:00

[GoogleCodeExporter]

[root@172-1-4-96 fastdfstest]# fdfs_monitor  /etc/fdfs/client.conf 
[2014-04-25 17:02:18] DEBUG - base_path=/home/yuqing/fastdfs, 
connect_timeout=30, network_timeout=60, tracker_server_count=1, 
anti_steal_token=0, anti_steal_secret_key length=0, use_connection_pool=0, 
g_connection_pool_max_idle_time=3600s, use_storage_id=0, storage server id 
count: 0

server_count=1, server_index=0

tracker server is 172.1.4.96:2122

group count: 1

Group 1:
group name = group1
disk total space = 95193 MB
disk free space = 84083 MB
trunk free space = 0 MB
storage server count = 2
active server count = 2
storage server port = 23000
storage HTTP port = 8888
store path count = 1
subdir count per path = 256
current write server index = 1
current trunk file id = 0

    Storage 1:
        id = 172.1.2.102
        ip_addr = 172.1.2.102 (172-1-2-102.lightspeed.hstntx.sbcglobal.net)  ACTIVE
        http domain = 
        version = 5.01
        join time = 2014-04-18 11:01:24
        up time = 2014-04-25 16:35:40
        total storage = 444041 MB
        free storage = 334725 MB
        upload priority = 10
        store_path_count = 1
        subdir_count_per_path = 256
        storage_port = 23000
        storage_http_port = 8888
        current_write_path = 0
        source storage id= 172.1.4.96
        if_trunk_server= 0
        total_upload_count = 2336
        success_upload_count = 2336
        total_append_count = 300093
        success_append_count = 300093
        total_modify_count = 143
        success_modify_count = 143
        total_truncate_count = 236
        success_truncate_count = 236
        total_set_meta_count = 24
        success_set_meta_count = 24
        total_delete_count = 2144
        success_delete_count = 2144
        total_download_count = 360
        success_download_count = 360
        total_get_meta_count = 14
        success_get_meta_count = 14
        total_create_link_count = 0
        success_create_link_count = 0
        total_delete_link_count = 0
        success_delete_link_count = 0
        total_upload_bytes = 7000114688
        success_upload_bytes = 7000114688
        total_append_bytes = 1333995
        success_append_bytes = 1333995
        total_modify_bytes = 2160
        success_modify_bytes = 2160
        stotal_download_bytes = 52062806
        success_download_bytes = 52062806
        total_sync_in_bytes = 2171421328
        success_sync_in_bytes = 2160415576
        total_sync_out_bytes = 6555852724
        success_sync_out_bytes = 6552353095
        total_file_open_count = 304704
        success_file_open_count = 304704
        total_file_read_count = 537
        success_file_read_count = 537
        total_file_write_count = 337187
        success_file_write_count = 337187
        last_heart_beat_time = 2014-04-25 17:01:50
        last_source_update = 2014-04-25 16:49:17
        last_sync_update = 2014-04-25 16:56:42
        last_synced_timestamp = 2014-04-25 15:57:10 (02m:29s delay)
    Storage 2:
        id = 172.1.4.96
        ip_addr = 172.1.4.96 (172-1-4-96.lightspeed.hstntx.sbcglobal.net)  ACTIVE
        http domain = 
        version = 5.01
        join time = 2014-04-18 10:54:31
        up time = 2014-04-25 16:40:41
        total storage = 95193 MB
        free storage = 84083 MB
        upload priority = 10
        store_path_count = 1
        subdir_count_per_path = 256
        storage_port = 23000
        storage_http_port = 8888
        current_write_path = 0
        source storage id= 
        if_trunk_server= 0
        total_upload_count = 703
        success_upload_count = 703
        total_append_count = 280001
        success_append_count = 280001
        total_modify_count = 98
        success_modify_count = 98
        total_truncate_count = 5
        success_truncate_count = 5
        total_set_meta_count = 2
        success_set_meta_count = 2
        total_delete_count = 663
        success_delete_count = 663
        total_download_count = 275
        success_download_count = 275
        total_get_meta_count = 2
        success_get_meta_count = 2
        total_create_link_count = 0
        success_create_link_count = 0
        total_delete_link_count = 0
        success_delete_link_count = 0
        total_upload_bytes = 2019616983
        success_upload_bytes = 2019616983
        total_append_bytes = 1244531
        success_append_bytes = 1244531
        total_modify_bytes = 3105
        success_modify_bytes = 3105
        stotal_download_bytes = 18203129
        success_download_bytes = 18203129
        total_sync_in_bytes = 6566400359
        success_sync_in_bytes = 6555399271
        total_sync_out_bytes = 2160890165
        success_sync_out_bytes = 2160415576
        total_file_open_count = 289777
        success_file_open_count = 289777
        total_file_read_count = 321
        success_file_read_count = 321
        total_file_write_count = 320372
        success_file_write_count = 320372
        last_heart_beat_time = 2014-04-25 17:02:12
        last_source_update = 2014-04-25 15:59:39
        last_sync_update = 2014-04-25 17:02:12
        last_synced_timestamp = 2014-04-25 15:54:21 (54m:56s delay)

Original comment by xcl3...@gmail.com on 25 Apr 2014 at 9:01

[GoogleCodeExporter]

truncate 提交成功，但是内容不清空

Original comment by xcl3...@gmail.com on 25 Apr 2014 at 9:12

[GoogleCodeExporter]

重启apache 可以连接tracker，但是不能truncate之前文件

Original comment by xcl3...@gmail.com on 25 Apr 2014 at 9:13

[GoogleCodeExporter]

[2014-04-25 17:35:05] ERROR - file: tracker_proto.c, line: 48, server: 
172.1.2.102:23000, response status 17 != 0
[2014-04-25 17:35:05] DEBUG - file: storage_service.c, line: 5912, client ip: 
172.1.2.102, file 
/home/yuqing/fastdfs/data/00/15/rAECZlNXcQGEdk0-AAAAANJEtCU128.txt,  my file 
size: 1066757 >= src file size: 840006, do not append

Original comment by xcl3...@gmail.com on 25 Apr 2014 at 9:34

[GoogleCodeExporter]

rm  /home/yuqing/fastdfs/data/00/15/rAECZlNXcQGEdk0-AAAAANJEtCU128.txt 
将两个storage 都清理后，恢复正常

Original comment by xcl3...@gmail.com on 25 Apr 2014 at 10:00

[GoogleCodeExporter]

最新版本中修复了这个问题，谢谢反馈！

Original comment by happyfis...@gmail.com on 6 May 2014 at 2:49

[GoogleCodeExporter]

东西很好！不客气！

Original comment by xcl3...@gmail.com on 21 May 2014 at 5:43