Re[2]: COPY и несуществующая директория = 500 Internal Server Error

Михаил Монашёв postmaster at softsearch.ru
Sun Dec 29 10:11:29 UTC 2013


Здравствуйте, Maxim.

>> Бага или фича?
>> 
>> Если  через  WebDAV  копируется  несуществующий  файл  в  существующей
>> директории, то выдаётся 404. Но если копируется файл из несуществующей
>> директории  в  неё  же,  то  выдаётся 500 - Internal Server Error. Это
>> правильное поведение или должно 404 тоже выдаваться?

> Если исходный файл/каталог не сущетсвует, то в любом случае должно 
> выдаваться 404.

>> Пример:
>> копируем http://i39.beon.ru/17/74/1467417/47/avatars/4.jpeg
>> в  http://i39.beon.ru/17/74/1467417/47/avatars/4.jpeg.tmp
>> и получаем: 500 Internal Server Error
>> 
>> в error_log-е:
>> 2013/12/28 11:54:28 [crit] 2845#0: *4749150 open()
>> "/opt2/beon/i39/17/74/1467417/47/avatars/4.jpeg.tmp" failed (2: No
>> such file or directory), client: 89.208.146.210, server:
>> i39.beon.ru, request: "COPY
>> http://i39.beon.ru/17/74/1467417/47/avatars/4.jpeg HTTP/1.1", host:
>> "i39.beon.ru"
>> 
>> в access.log-e:
>> 28/Dec/2013:11:54:28 +0400 500 89.208.146.210 353 i39.beon.ru
>> "COPY http://i39.beon.ru/17/74/1467417/47/avatars/4.jpeg HTTP/1.1"
>> "-" "-" "-" "-" "-" "-" "close"

> Должно быть так:

> 2013/12/28 16:51:35 [error] 33014#0: *1 lstat()
> "/path/to/foo/bar/bazz" failed (2: No such file or directory),
> client: 127.0.0.1, server: , request: "COPY /foo/bar/bazz HTTP/1.1",
> host: "localhost"
> 127.0.0.1 - - [28/Dec/2013:16:51:35 +0400] "COPY /foo/bar/bazz HTTP/1.1" 404 168 "-" "-"

> То, что у тебя сломался open(), намекает на то, что в процессе 
> выполнения этого запроса кто-то удалил каталог.

Каталоги там никто не удаляет точно. Вся работа идёт через nginx, а он
удалять  каталоги  не  умеет  и  на  встроенном перле у меня ничего не
написано. И ошибка эта воспроизводится не всегда.

Ошибка: Couldn't copy http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif => http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif.tmp: 500 Internal Server Error

Посмотрел debug-лог. Я там тоже накрутил с конфигом, но 500 всёравно
быть не должно ИМХО:

2013/12/29 14:00:55 [debug] 78336#0: *10484311 accept: 89.208.146.210 fd:4
2013/12/29 14:00:55 [debug] 78336#0: *10484311 post event 00000008032442A0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 delete posted event 00000008032442A0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http wait request handler
2013/12/29 14:00:55 [debug] 78336#0: *10484311 posix_memalign: 000000080303E300:256 @16
2013/12/29 14:00:55 [debug] 78336#0: *10484311 malloc: 0000000803007800:1024
2013/12/29 14:00:55 [debug] 78336#0: *10484311 recv: eof:0, avail:1, err:0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 recv: fd:4 188 of 1024
2013/12/29 14:00:55 [debug] 78336#0: *10484311 reusable connection: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 posix_memalign: 000000080308F000:4096 @16
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http process request line
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http request line: "COPY http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif HTTP/1.1"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http uri: "/43/96/1009643/43/avatars/9.gif"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http args: ""
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http exten: "gif"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http process request header line
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http header: "Connection: close"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http header: "Host: b.i41.beon.ru"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http header: "Command-ID: 1"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http header: "Destination: http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif.tmp"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http header done
2013/12/29 14:00:55 [debug] 78336#0: *10484311 generic phase: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 rewrite phase: 1
2013/12/29 14:00:55 [debug] 78336#0: *10484311 posix_memalign: 0000000803091000:4096 @16
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http script regex: "^(/\d+/\d+/\d+/)\d+/(avatars/.+|design/.+|0\.(?:gif|jpeg|png|mp3))$"
2013/12/29 14:00:55 [notice] 78336#0: *10484311 "^(/\d+/\d+/\d+/)\d+/(avatars/.+|design/.+|0\.(?:gif|jpeg|png|mp3))$" matches "/43/96/1009643/43/avatars/9.gif", client: 89.208.146.210, server: i41.beon.ru, request: "COPY http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif HTTP/1.1", host: "b.i41.beon.ru"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http script copy: "/"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http script capture: "/43/96/1009643/"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http script capture: "avatars/9.gif"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http script regex end
2013/12/29 14:00:55 [notice] 78336#0: *10484311 rewritten data: "//43/96/1009643/avatars/9.gif", args: "", client: 89.208.146.210, server: i41.beon.ru, request: "COPY http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif HTTP/1.1", host: "b.i41.beon.ru"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 test location: "/"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 test location: "robots.txt"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 using configuration "/"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http cl:-1 max:20971520
2013/12/29 14:00:55 [debug] 78336#0: *10484311 rewrite phase: 3
2013/12/29 14:00:55 [debug] 78336#0: *10484311 post rewrite phase: 4
2013/12/29 14:00:55 [debug] 78336#0: *10484311 generic phase: 5
2013/12/29 14:00:55 [debug] 78336#0: *10484311 generic phase: 6
2013/12/29 14:00:55 [debug] 78336#0: *10484311 generic phase: 7
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access phase: 8
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access: D292D059 000000FF 0000007F
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access: D292D059 000000FF 0000000A
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access: D292D059 F8FFFFFF D892D059
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access: D292D059 FFFFFFFF E092D059
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access: D292D059 FCFFFFFF D492D059
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access: D292D059 FEFFFFFF D292D059
2013/12/29 14:00:55 [debug] 78336#0: *10484311 access phase: 9
2013/12/29 14:00:55 [debug] 78336#0: *10484311 post access phase: 10
2013/12/29 14:00:55 [debug] 78336#0: *10484311 content phase: 11
2013/12/29 14:00:55 [debug] 78336#0: *10484311 content phase: 12
2013/12/29 14:00:55 [debug] 78336#0: *10484311 content phase: 13
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http copy from: "/opt2/beon/i41//43/96/1009643/avatars/9.gif"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http copy to: "/opt2/beon/i41/43/96/1009643/43/avatars/9.gif.tmp"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 malloc: 0000000806E68000:65536
2013/12/29 14:00:55 [crit] 78336#0: *10484311 open() "/opt2/beon/i41/43/96/1009643/43/avatars/9.gif.tmp" failed (2: No such file or directory), client: 89.208.146.210, server: i41.beon.ru, request: "COPY http://b.i41.beon.ru/43/96/1009643/43/avatars/9.gif HTTP/1.1", host: "b.i41.beon.ru"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http finalize request: 500, "//43/96/1009643/avatars/9.gif?" a:1, c:1
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http special response: 500, "//43/96/1009643/avatars/9.gif?"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http set discard body
2013/12/29 14:00:55 [debug] 78336#0: *10484311 HTTP/1.1 500 Internal Server Error
2013/12/29 14:00:55 [debug] 78336#0: *10484311 write new buf t:1 f:0 0000000803091170, pos 0000000803091170, size: 161 file: 0, size: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http write filter: l:0 f:0 s:161
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http output filter "//43/96/1009643/avatars/9.gif?"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http copy filter: "//43/96/1009643/avatars/9.gif?"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 image filter
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http postpone filter "//43/96/1009643/avatars/9.gif?" 0000000803091348
2013/12/29 14:00:55 [debug] 78336#0: *10484311 write old buf t:1 f:0 0000000803091170, pos 0000000803091170, size: 161 file: 0, size: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 write new buf t:0 f:0 0000000000000000, pos 00000000006DC720, size: 140 file: 0, size: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 write new buf t:0 f:0 0000000000000000, pos 00000000006DB5C0, size: 52 file: 0, size: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http write filter: l:1 f:0 s:353
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http write filter limit 131072
2013/12/29 14:00:55 [debug] 78336#0: *10484311 writev: 353 of 353
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http write filter 0000000000000000
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http copy filter: 0 "//43/96/1009643/avatars/9.gif?"
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http finalize request: 0, "//43/96/1009643/avatars/9.gif?" a:1, c:1
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http request count:1 blk:0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http close request
2013/12/29 14:00:55 [debug] 78336#0: *10484311 http log handler
2013/12/29 14:00:55 [debug] 78336#0: *10484311 free: 000000080308F000, unused: 7
2013/12/29 14:00:55 [debug] 78336#0: *10484311 free: 0000000803091000, unused: 3192
2013/12/29 14:00:55 [debug] 78336#0: *10484311 close http connection: 4
2013/12/29 14:00:55 [debug] 78336#0: *10484311 reusable connection: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 free: 0000000803007800
2013/12/29 14:00:55 [debug] 78336#0: *10484311 free: 000000080303E200, unused: 0
2013/12/29 14:00:55 [debug] 78336#0: *10484311 free: 000000080303E300, unused: 144


-- 
С уважением,
 Михаил                          mailto:postmaster at softsearch.ru



Подробная информация о списке рассылки nginx-ru