Volume server take long time to retrieve a file

61 views
Skip to first unread message

TianHaw Tsai

unread,
Jun 20, 2016, 12:26:28 AM6/20/16
to Seaweed File System

不知道為什麼，volume server有時候會需要很長的時間才會回傳檔案。例如下面的例子顯示我在Node.js裡發出六個檔案的讀取要求，以及對應的timestamp（epoch time in millisecond）。

 

可以看到，master server回應volume lookup的速度都很快，但接下來當request繼續傳給volume server的時候，有兩個檔案6,0af2a1858a_1、6,0af2a1858a_2分別花了三秒和四秒才開始接收到資料。

 

但在volume server的log中看不出為什麼，因為都顯示時間為11:27:51，不確定這些時間是接收到request的時間、檔案讀取完成的時間、開始網路傳輸檔案的時間，還是網路傳輸檔案結束的時間。

 

WFS: try to find 6,0af2a1858a_0 - 1466393271116

WFS: try to find 1,0d95a552f8_1 - 1466393271119

WFS: try to find 6,0af2a1858a_2 - 1466393271120

WFS: try to find 6,0af2a1858a_1 - 1466393271125

WFS: try to find 1,0d95a552f8_2 - 1466393271126

WFS: try to find 1,0d95a552f8_0 - 1466393271127

WFS: Find 1,0d95a552f8_1 finished, starting read - 1466393271176

WFS: Find 6,0af2a1858a_1 finished, starting read - 1466393271179

WFS: Find 6,0af2a1858a_0 finished, starting read - 1466393271181

WFS: Find 1,0d95a552f8_2 finished, starting read - 1466393271182

WFS: Find 1,0d95a552f8_0 finished, starting read - 1466393271185

WFS: Starts receiving file 1,0d95a552f8_1 data - 1466393271195

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/9e1d48b5-15a2-4a3e-89a6-3495c7157c73/tmb 85.588 ms

WFS: Starts receiving file 1,0d95a552f8_2 data - 1466393271200

WFS: Starts receiving file 1,0d95a552f8_0 data - 1466393271202

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/9e1d48b5-15a2-4a3e-89a6-3495c7157c73/full 92.257 ms

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/9e1d48b5-15a2-4a3e-89a6-3495c7157c73/org 98.125 ms

WFS: Find 6,0af2a1858a_2 finished, starting read - 1466393271223

WFS: Starts receiving file 6,0af2a1858a_0 data - 1466393271527

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/org 418.204 ms

WFS: Starts receiving file 6,0af2a1858a_1 data - 1466393274531

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/tmb 3422.090 ms

WFS: Starts receiving file 6,0af2a1858a_2 data - 1466393276027

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/full 4917.622 ms

 

[Volume Server 1 Log]

I0620 11:27:51   997 volume_server_handlers_read.go:41] volume 6 reading Cookie:4070671754, Id:11, Size:0, DataSize:0, Name: , Mime:

I0620 11:27:51   997 volume_server_handlers_read.go:68] read bytes 6305 error <nil>

I0620 11:27:51   997 volume_server_handlers_read.go:41] volume 6 reading Cookie:4070671754, Id:10, Size:0, DataSize:0, Name: , Mime:

I0620 11:27:51   997 volume_server_handlers_read.go:68] read bytes 58320 error <nil>

I0620 11:27:51   997 volume_server_handlers_read.go:41] volume 6 reading Cookie:4070671754, Id:12, Size:0, DataSize:0, Name: , Mime:

I0620 11:27:51   997 volume_server_handlers_read.go:68] read bytes 39939 error <nil>

 

[Volume Server 2 Log]

I0620 11:27:51   993 volume_server_handlers_read.go:41] volume 1 reading Cookie:2510639864, Id:14, Size:0, DataSize:0, Name: , Mime:

I0620 11:27:51   993 volume_server_handlers_read.go:68] read bytes 6672 error <nil>

I0620 11:27:51   993 volume_server_handlers_read.go:41] volume 1 reading Cookie:2510639864, Id:15, Size:0, DataSize:0, Name: , Mime:

I0620 11:27:51   993 volume_server_handlers_read.go:68] read bytes 40555 error <nil>

I0620 11:27:51   993 volume_server_handlers_read.go:41] volume 1 reading Cookie:2510639864, Id:13, Size:0, DataSize:0, Name: , Mime:

I0620 11:27:51   993 volume_server_handlers_read.go:68] read bytes 62043 error <nil>

 

這個狀況不是每次都會出現，而且一但出現以後，立刻再重複同樣的request，結果都會正常，即使將WeedFS所在的電腦重新開機也無法reproduce這個問題，必須再等個一兩天才會產生這個問題。例如在上面問題產生的幾分鐘之內我重複上面的要求，結果取得檔案的時間就都很快：

 

WFS: try to find 1,0d95a552f8_0 - 1466393651454

WFS: try to find 6,0af2a1858a_2 - 1466393651455

WFS: try to find 1,0d95a552f8_1 - 1466393651456

WFS: try to find 6,0af2a1858a_1 - 1466393651456

WFS: try to find 1,0d95a552f8_2 - 1466393651457

WFS: try to find 6,0af2a1858a_0 - 1466393651461

WFS: Find 6,0af2a1858a_2 finished, starting read - 1466393651463

WFS: Find 1,0d95a552f8_1 finished, starting read - 1466393651465

WFS: Find 1,0d95a552f8_0 finished, starting read - 1466393651466

WFS: Find 6,0af2a1858a_0 finished, starting read - 1466393651467

WFS: Find 1,0d95a552f8_2 finished, starting read - 1466393651469

WFS: Find 6,0af2a1858a_1 finished, starting read - 1466393651471

WFS: Starts receiving file 1,0d95a552f8_1 data - 1466393651474

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/9e1d48b5-15a2-4a3e-89a6-3495c7157c73/tmb 25.333 ms

WFS: Starts receiving file 1,0d95a552f8_2 data - 1466393651477

WFS: Starts receiving file 1,0d95a552f8_0 data - 1466393651478

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/9e1d48b5-15a2-4a3e-89a6-3495c7157c73/full 31.037 ms

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/9e1d48b5-15a2-4a3e-89a6-3495c7157c73/org 33.299 ms

WFS: Starts receiving file 6,0af2a1858a_2 data - 1466393651485

WFS: Starts receiving file 6,0af2a1858a_0 data - 1466393651486

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/full 38.172 ms

WFS: Starts receiving file 6,0af2a1858a_1 data - 1466393651490

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/tmb 43.525 ms

GET /v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/org 46.415 ms

 

我的開發環境是把WeedFS的master和兩個volume server都架在同一台Ubuntu 14.04電腦上頭，Node.js是在另一台電腦上，兩台電腦以高速區域網路連接，所以應該不是網路慢造成的問題。Ubuntu上使用的檔案系統為btrfs。WeedFS啟動的設定為：

 

weed -v=100 master -mdir="/home/vas/SeaweedFS/MasterData" >> /home/dev/SeaweedFS/Master.log 2>&1

 

weed -v=100 volume -dir="/home/vas/SeaweedFS/data1" -max=7 -ip "192.168.1.213" -mserver="localhost:9333" -port=8080 >> /home/dev/SeaweedFS/VolumeSvr1.log 2>&1

 

weed -v=100 volume -dir="/home/vas/SeaweedFS/data2" -max=7 -ip "192.168.1.213" -mserver="localhost:9333" -port=8081 >> /home/dev/SeaweedFS/VolumeSvr2.log 2>&1

 

TianHaw Tsai

unread,
Jun 20, 2016, 12:32:15 AM6/20/16
to Seaweed File System
使用的版本為0.70版，更早先的0.70beta版也會有一樣的狀況

Chris Lu

unread,
Jun 20, 2016, 1:28:23 AM6/20/16
to Seaweed File System
How does this path “/v1/photo/81403a5a-6ce6-4b8a-9e22-801d47ee62fe/1e8492a8-8982-4e98-87e2-4ffd1097cd42/full” get translated to the file id? Is it by the filer server?

Chris

On Sun, Jun 19, 2016 at 9:32 PM, TianHaw Tsai <howg...@gmail.com> wrote:
使用的版本為0.70版，更早先的0.70beta版也會有一樣的狀況

--
You received this message because you are subscribed to the Google Groups "Seaweed File System" group.
To unsubscribe from this group and stop receiving emails from it, send an email to seaweedfs+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

TianHaw Tsai

unread,
Jun 20, 2016, 1:37:42 AM6/20/16
to Seaweed File System
I stored this mapping in a database. After getting the fid from the database, I print the "WFS: try to find FID - TIMESTAMP" log message and send a "dir/lookup?volumeId=" request to the master server.

Chris Lu

unread,
Jun 20, 2016, 1:58:44 AM6/20/16
to Seaweed File System
Could it be there are too many connections into the volume server? Or the volume server's memory is swapped to disk because of inactivity?

Chris

On Sun, Jun 19, 2016 at 10:37 PM, TianHaw Tsai <howg...@gmail.com> wrote:
I stored this mapping in a database. After getting the fid from the database, I print the "WFS: try to find FID - TIMESTAMP" log message and send a "dir/lookup?volumeId=" request to the master server.

--
Reply all
Reply to author
Forward
0 new messages