Mediatomb log showing transcoding is launched two times for a single media file.

mediatomb.log (text/plain), 11.39 KB, created by eipi on 2012-12-08 23:36:54 UTC

2012-12-08 23:43:32   DEBUG: [../src/timer.h:79] addTimerSubscriber(): adding subscriber...
2012-12-08 23:43:32   DEBUG: [../src/timer.cc:67] triggerWait(): triggerWait. - 1 subscriber(s)
2012-12-08 23:43:32   DEBUG: [../src/timer.cc:77] triggerWait(): sleeping...
2012-12-08 23:45:14   DEBUG: [../src/web_callbacks.cc:72] create_request_handler(): Filename: /content/media/object_id/9939/res_id/none/pr_name/multifunctional/tr, Path: (null)
2012-12-08 23:45:14   DEBUG: [../src/file_request_handler.cc:345] open(): start
2012-12-08 23:45:14   DEBUG: [../src/file_request_handler.cc:360] open(): full url (filename): /content/media/object_id/9939/res_id/none/pr_name/multifunctional/tr, parameters: object_id/9939/res_id/none/pr_name/multifunctional/tr
2012-12-08 23:45:14   DEBUG: [../src/file_request_handler.cc:370] open(): Opening media file with object id 9939
2012-12-08 23:45:14   DEBUG: [../src/file_request_handler.cc:506] open(): path: /media/data.pool/mm/Videos/Comedies/Ca D#U00e9tourne - Le Triomphe De Bali-Balo Ou La Splendeur De La Honte Ou L'invasion Des Pervers Polymorphes.avi
2012-12-08 23:45:14   DEBUG: [../src/file_request_handler.cc:519] open(): fetching resource id -1
2012-12-08 23:45:14   DEBUG: [../src/transcoding/transcode_ext_handler.cc:90] open(): start
2012-12-08 23:45:14   DEBUG: [../src/tools.cc:1056] normalizePath(): Normalizing path: /tmp//mt_transcode_V389OW
2012-12-08 23:45:14   DEBUG: [../src/transcoding/transcode_ext_handler.cc:322] open(): creating fifo: /tmp/mt_transcode_V389OW
2012-12-08 23:45:14    INFO: Arguments: %in %out
2012-12-08 23:45:14   DEBUG: [../src/process_executor.cc:77] ProcessExecutor(): Launched process /etc/mediatomb/transcoder.sh, pid: 18151
2012-12-08 23:45:14   DEBUG: [../src/process_executor.cc:71] ProcessExecutor(): Launching process: /etc/mediatomb/transcoder.sh
2012-12-08 23:45:14   DEBUG: 2012-12-08 23:45:14   DEBUG: [../src/singleton.cc:73] registerSingleton(): registering new singleton... - 9 -> 10
[../src/io_handler_buffer_helper.cc:224] staticThreadProc(): starting buffer thread... thread: -1323308224
2012-12-08 23:45:18   DEBUG: [../src/web_callbacks.cc:72] create_request_handler(): Filename: /content/media/object_id/9939/res_id/none/pr_name/multifunctional/tr/1, Path: (null)
2012-12-08 23:45:18   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 0.00%  (bufSize: 5242880; a: 0; b: 0)
2012-12-08 23:45:18   DEBUG: [../src/file_request_handler.cc:345] open(): start
2012-12-08 23:45:18   DEBUG: [../src/file_request_handler.cc:360] open(): full url (filename): /content/media/object_id/9939/res_id/none/pr_name/multifunctional/tr/1, parameters: object_id/9939/res_id/none/pr_name/multifunctional/tr/1
2012-12-08 23:45:18   DEBUG: [../src/file_request_handler.cc:370] open(): Opening media file with object id 9939
2012-12-08 23:45:18   DEBUG: [../src/file_request_handler.cc:506] open(): path: /media/data.pool/mm/Videos/Comedies/Ca D#U00e9tourne - Le Triomphe De Bali-Balo Ou La Splendeur De La Honte Ou L'invasion Des Pervers Polymorphes.avi
2012-12-08 23:45:18   DEBUG: [../src/file_request_handler.cc:519] open(): fetching resource id -1
2012-12-08 23:45:18   DEBUG: [../src/transcoding/transcode_ext_handler.cc:90] open(): start
2012-12-08 23:45:18   DEBUG: [../src/tools.cc:1056] normalizePath(): Normalizing path: /tmp//mt_transcode_R5WWOW
2012-12-08 23:45:18   DEBUG: [../src/transcoding/transcode_ext_handler.cc:322] open(): creating fifo: /tmp/mt_transcode_R5WWOW
2012-12-08 23:45:18    INFO: Arguments: %in %out
2012-12-08 23:45:18   DEBUG: [../src/process_executor.cc:77] ProcessExecutor(): Launched process /etc/mediatomb/transcoder.sh, pid: 18182
2012-12-08 23:45:18   DEBUG: [../src/process_executor.cc:71] ProcessExecutor(): Launching process: /etc/mediatomb/transcoder.sh
2012-12-08 23:45:18   DEBUG: [../src/io_handler_buffer_helper.cc:224] staticThreadProc(): starting buffer thread... thread: -1338000576
2012-12-08 23:45:18   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 0.00%  (bufSize: 5242880; a: 0; b: 0)
2012-12-08 23:45:18   DEBUG: [../src/buffered_io_handler.cc:189] threadProc(): buffer: initial fillsize reached
2012-12-08 23:45:19   DEBUG: [../src/buffered_io_handler.cc:189] threadProc(): buffer: initial fillsize reached
2012-12-08 23:45:19   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 42.50%  (bufSize: 5242880; a: 1048576; b: 3276800)
2012-12-08 23:45:19   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 9.30%  (bufSize: 5242880; a: 1048576; b: 1536000)
2012-12-08 23:45:20   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 81.95%  (bufSize: 5242880; a: 1048576; b: 102400)
2012-12-08 23:45:22   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 2097152; b: 1048576)
2012-12-08 23:45:24   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 3145728; b: 2097152)
2012-12-08 23:45:26   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 3145728; b: 2097152)
2012-12-08 23:45:29   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 4194304; b: 3145728)
2012-12-08 23:45:29   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 4194304; b: 3145728)
2012-12-08 23:45:33   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 0; b: 4194304)
2012-12-08 23:45:33   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 0; b: 4194304)
2012-12-08 23:45:36   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 1048576; b: 0)
2012-12-08 23:45:37   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 1048576; b: 0)
2012-12-08 23:45:40   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 2097152; b: 1048576)
2012-12-08 23:45:41   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 2097152; b: 1048576)
2012-12-08 23:45:45   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 3145728; b: 2097152)
2012-12-08 23:45:46   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 3145728; b: 2097152)
2012-12-08 23:45:50   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 4194304; b: 3145728)
2012-12-08 23:45:50   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 4194304; b: 3145728)
2012-12-08 23:45:54   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 0; b: 4194304)
2012-12-08 23:45:55   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 0; b: 4194304)
2012-12-08 23:45:57   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 1048576; b: 0)
2012-12-08 23:46:01   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 1048576; b: 0)
2012-12-08 23:46:01   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 2097152; b: 1048576)
2012-12-08 23:46:04   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 2097152; b: 1048576)
2012-12-08 23:46:08   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 3145728; b: 2097152)
2012-12-08 23:46:12   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 4194304; b: 3145728)
2012-12-08 23:46:17   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 0; b: 4194304)
2012-12-08 23:46:24   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 1048576; b: 0)
2012-12-08 23:46:32   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 2097152; b: 1048576)
2012-12-08 23:46:36   DEBUG: [../src/buffered_io_handler.cc:96] threadProc(): buffer fill level: 80.00%  (bufSize: 5242880; a: 3145728; b: 2097152)
2012-12-08 23:46:37   DEBUG: [../src/server.cc:362] upnp_callback(): start
2012-12-08 23:46:37   DEBUG: [../src/server.cc:444] upnp_actions(): start
2012-12-08 23:46:37   DEBUG: [../src/upnp_cds_actions.cc:182] process_action_request(): start
2012-12-08 23:46:37   DEBUG: [../src/upnp_cds_actions.cc:45] upnp_action_Browse(): start
2012-12-08 23:46:37   DEBUG: [../src/storage/sql_storage.cc:785] browse(): QUERY: SELECT "f"."id","f"."ref_id","f"."parent_id","f"."object_type","f"."upnp_class","f"."dc_title","f"."location","f"."location_hash","f"."metadata","f"."auxdata","f"."resources","f"."update_id","f"."mime_type","f"."flags","f"."track_number","f"."service_id","rf"."upnp_class","rf"."location","rf"."metadata","rf"."auxdata","rf"."resources","rf"."mime_type","rf"."service_id","as"."persistent" FROM "mt_cds_object" "f" LEFT JOIN "mt_cds_object" "rf" ON "f"."ref_id"="rf"."id" LEFT JOIN "mt_autoscan" "as" ON "as"."obj_id"="f"."id"  WHERE "f"."parent_id"=106 ORDER BY ("f"."object_type"=1) DESC, "f"."dc_title" LIMIT 15 OFFSET 0
2012-12-08 23:46:37   DEBUG: [../src/cds_resource_manager.cc:485] addResources(): extended protocolInfo: http-get:*:video/mpeg:DLNA.ORG_OP=00;DLNA.ORG_CI=1;DLNA.ORG_FLAGS=012000000000000000000000000000000
2012-12-08 23:46:37   DEBUG: [../src/cds_resource_manager.cc:485] addResources(): extended protocolInfo: http-get:*:video/transcode:DLNA.ORG_OP=01;DLNA.ORG_CI=0
2012-12-08 23:46:37   DEBUG: [../src/cds_resource_manager.cc:485] addResources(): extended protocolInfo: http-get:*:application/octet-stream:DLNA.ORG_OP=01;DLNA.ORG_CI=0
2012-12-08 23:46:37   DEBUG: [../src/cds_resource_manager.cc:485] addResources(): extended protocolInfo: http-get:*:video/mpeg:DLNA.ORG_OP=00;DLNA.ORG_CI=1;DLNA.ORG_FLAGS=012000000000000000000000000000000
2012-12-08 23:46:37   DEBUG: [../src/cds_resource_manager.cc:485] addResources(): extended protocolInfo: http-get:*:video/transcode:DLNA.ORG_OP=01;DLNA.ORG_CI=0
2012-12-08 23:46:37   DEBUG: [../src/upnp_cds_actions.cc:138] upnp_action_Browse(): end
2012-12-08 23:46:37   DEBUG: [../src/upnp_cds_actions.cc:209] process_action_request(): ContentDirectoryService::process_action_request: end
2012-12-08 23:46:37   DEBUG: [../src/server.cc:423] upnp_callback(): returning 0
2012-12-08 23:46:37   DEBUG: [../src/io_handler_buffer_helper.cc:227] staticThreadProc(): buffer thread shut down. thread: -1338000576
2012-12-08 23:46:37   DEBUG: [../src/process_io_handler.cc:438] close(): terminating process, closing /tmp/mt_transcode_R5WWOW
2012-12-08 23:46:37   DEBUG: [../src/process.cc:151] kill_proc(): KILLING TERM PID: 18182
2012-12-08 23:46:38   DEBUG: [../src/process.cc:160] kill_proc(): KILLING INT PID: 18182
2012-12-08 23:46:39   DEBUG: [../src/process.cc:169] kill_proc(): KILLING KILL PID: 18182
2012-12-08 23:46:40   DEBUG: [../src/process_io_handler.cc:438] close(): terminating process, closing /tmp/mt_transcode_R5WWOW
2012-12-08 23:50:26   DEBUG: [../src/server.cc:362] upnp_callback(): start