Force DLNA Index, Auto Decrypt, Auto Shrink

[af123]

I've just pushed webif version 1.2.2-5 to the package server. That should fix the dlna diagnostics screen. It also fixes a race condition in the one-off triggering of auto.
No other changes to auto over and above the previous test package though - I'll have some more time to look at that in a day or two.

 

[MymsMan]

Unfortunately 1.2.2-5 seems to have broken the Decryption without DLNA indexing (or hasn't that made it into production yet?)

Today Pointless and The Chase were both flattened at 6pm but were not Decrypted until 7pm (along with Countdown)
Yesterday they were both decrypted at 6:10

 

[MymsMan]

@MymsMan. I presume the sidecar files are needed to decrypt on the fly: the hmt file definitely is. What if you use a symbolic link to point to dummy sidecar files? If these dummy files were configured so that the recording appears to be full length from the start your method might work.

I tried copying the sidecars from a previous recording and while some information from the HMT (e.g. decryption flag) is used it does not appear that the full program file length is contained within the HMT http://wiki.hummy.tv/wiki/HMT_File_Format so cant be used to override current actual file length

 

[af123]

Unfortunately 1.2.2-5 seems to have broken the Decryption without DLNA indexing (or hasn't that made it into production yet?)

It should still be working. I'll have a look at my logs later and see if it's still working for me.
Anyone else?

 

[MontysEvilTwin]

It should still be working. I'll have a look at my logs later and see if it's still working for me.
Anyone else?

Mine is still working, but occasionally (presumably if the recording happens to finish at the 'right' time) the standard processing takes over: I had a recording that finished just before 9pm that started decrypting at 9pm. I know from the URL that it must have been the standard process as the URL was '127.0.0.x': it seems that items processed by the new method have URLs based on the IP address of the box (e.g. '192.168.0.x' in my case). One other thing I noticed with a timer recording that occurred in standby; it was not decrypted straight away after start-up but was decrypted at the next 10 minute point by the standard method.

 

[MymsMan]

It should still be working. I'll have a look at my logs later and see if it's still working for me.
Anyone else?

I am not quite sure what is going on.
I saw today that recordings ARE being decrypted before the Indexed icons but not until 20 minutes after the directory is flattened - I could see nothing obvious in the logs to explain why decrypt did not start in the intermediate auto cycle. Unfortunately I suffered a crash just before six today so don't have as many recordings as usual to study the logs for.

Yesterday I was out all day so the system was running unattended so don't know exactly went on but do know the system was recording between 6-6:30 so there is no logical reason for decryption not to run in that interval. (System probably shut down automatically at 6:30 and was manually start up when we returned just before 7)

 

[af123]

Log entries in auto.log for recording which are processed due to post-record trigger have the wrong timestamps (out by an hour).
The latest version of the recmon package fixes that (restart required).

 

[MontysEvilTwin]

I have looked at the auto.log files for three HDR-FOX units over the last couple of days. One is exclusively using the new decryption method, one is using a mixture of new and old, and one is only using the old method. I don't understand the difference in behaviour. I use auto-update on all machines, so all packages should be up to date. Is it just down to how quickly the DLNA server runs on a particular machine?

 

[af123]

The automatic decryption is triggered in two different ways and there is a locking system which prevents more than one running at a time.

A full scan is triggered every 10 minutes and looks at the whole recording tree. That one can take a minute or so to run depending on how many recordings you have and whether anything needs doing.

The other method is that whenever a recording completes, the recmon package kicks off a scan on just the directory containing the new recording. However, if it can't get the lock because another scan is already running (scheduled or another recording has recently ended) it will keep trying to get the lock for up to ten minutes before giving up. There isn't much logging around this process yet but I'll improve that in an update. If it has to give up then the recording will be picked up on the next scheduled auto run. There's also an evens chance that there won't be time to complete the decryption here before the box powers off if it was only awake for the recording.

At present the single directory scan doesn't trigger plugins which have registered an interest in being called following a full decryption scan (for example sweeper and flatten) but I have a solution for that awaiting integration.

I'll hopefully have an update later today which will improve things and give more insight into what's happening!

 

[MymsMan]

“Is there any point to which you would wish to draw my attention?'

'To the curious incident of the dog in the night-time.'

'The dog did nothing in the night-time.'

'That was the curious incident,' remarked Sherlock Holmes.”
― Arthur Conan Doyle, Silver Blaze

When I reported earlier

I saw today that recordings ARE being decrypted before the Indexed icons but not until 20 minutes after the directory is flattened - I could see nothing obvious in the logs to explain why decrypt did not start in the intermediate auto cycle.

I should have realised that the ABSENCE of log records was the curious incident!
In normal operation Flatten reports that it was unable to remove the directory of the currently active recordings every scan cycle and these messages were also missing from the log leading me to suspect that the regular Auto scan failed to run for that period - perhaps because it was unable to acquire the Lock. Unfortunately the message written on Lock failure is piped to NULL and lost.

Hopefully the promised updates will improve on the diagnostics and throw some more light on the situation, none of my Auto runs usually take anywhere close to ten minutes so there is no obvious reason why the lock would be unavailable.

 

[af123]

I've just uploaded some updated packages which increase the amount of logging and include other changes so that flatten and sweeper can run from the post-recording run. Can you see how these work for you? If nothing else there should be clues about why it is not always working.

 

[MymsMan]

This predates your recent updates but hopefully will be informative (Long log extract - I increased the logging level.)
Scheduled scans are set are set at :01, :11, :21 etc)

This evening I recorded Poldark, Vera and BBC news.
Vera was Flattened at 22:15 and then Decryption starts, using helper, at 22:21 (line 1551) but apparently never completes.
A single directory scan starts at 22:28 6 minutes after the end of the news at 22:22
No mention of Vera in 22:31 scan
Actual decryption doesn't occur to 22:51 (as part of 22:41 scan) when DLNA indexing has completed.

So how did the Recmon triggered scan get to start whilst the previous scheduled scan was in the middle of Decryption?
Edit: The three hour inactivity shutdown did trigger around then which I cancelled but strange if it killed the auto task but not the recmon triggered scan.

1636 19/04/2015 22:51:22 -   DETECTADS: Queued /media/My Video/Vera_20150419_2003.ts for advert detection
1635 19/04/2015 22:51:20 -   DETECTADS: Checking /media/My Video/Vera_20150419_2003.ts (ITV) for channel exclusion
1634 19/04/2015 22:51:20 - Done... 2.46 GiB in 475.544 seconds - 5.29 MiB/s
1633 19/04/2015 22:51:20 -   Removing/binning old copy.
1632 19/04/2015 22:43:25 -   DLNA: http://127.0.0.1:9000/web/media/24687.TS
1631 19/04/2015 22:43:25 -   DECRYPT: /media/My Video/Vera_20150419_2003
1630 19/04/2015 22:43:25 -   /media/My Video/Vera_20150419_2003.ts - has been indexed.
1629 19/04/2015 22:43:23 - Matched exclusion entry BBC * - skipping ad detection
1628 19/04/2015 22:43:23 -   DETECTADS: Checking /media/My Video/South Today_20150419_2222.ts (BBC ONE South) for channel exclusion
1627 19/04/2015 22:43:23 - Done... 253.09 MiB in 40.865 seconds - 6.19 MiB/s
1626 19/04/2015 22:43:22 -   Removing/binning old copy.
1625 19/04/2015 22:42:42 -   DLNA: http://127.0.0.1:9000/web/media/24689.TS
1624 19/04/2015 22:42:42 -   DECRYPT: /media/My Video/South Today_20150419_2222
1623 19/04/2015 22:42:42 -   /media/My Video/South Today_20150419_2222.ts - has been indexed.
1622 19/04/2015 22:42:41 - Matched exclusion entry BBC * - skipping ad detection
1621 19/04/2015 22:42:41 -   DETECTADS: Checking /media/My Video/BBC News_20150419_2159.ts (BBC ONE South) for channel exclusion
1620 19/04/2015 22:42:41 - Done... 646.79 MiB in 97.872 seconds - 6.61 MiB/s
1619 19/04/2015 22:42:40 -   Removing/binning old copy.
1618 19/04/2015 22:41:03 -   DLNA: http://127.0.0.1:9000/web/media/24688.TS
1617 19/04/2015 22:41:03 -   DECRYPT: /media/My Video/BBC News_20150419_2159
1616 19/04/2015 22:41:03 -   /media/My Video/BBC News_20150419_2159.ts - has been indexed.
1615 19/04/2015 22:41:02 - decrypt scan starting.
1614 19/04/2015 22:41:02 - Media scan starting, DLNA server status: 1
1613 19/04/2015 22:41:02 - -------------------------------------------------------
1612 19/04/2015 22:41:02 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
1611 19/04/2015 22:41:02 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
1610 19/04/2015 22:41:02 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
1609 19/04/2015 22:31:07 - Media scan completed in 5.137 seconds.
1608 19/04/2015 22:31:07 - expire scan completed in 0.266 seconds.
1607 19/04/2015 22:31:06 - expire scan starting.
1606 19/04/2015 22:31:06 - mp3 scan completed in 0.234 seconds.
1605 19/04/2015 22:31:06 - mp3 scan starting.
1604 19/04/2015 22:31:06 - mpg scan completed in 0.23 seconds.
1603 19/04/2015 22:31:06 - mpg scan starting.
1602 19/04/2015 22:31:06 - shrink scan completed in 0.231 seconds.
1601 19/04/2015 22:31:06 - shrink scan starting.
1600 19/04/2015 22:31:06 - dedup scan completed in 0.229 seconds.
1599 19/04/2015 22:31:05 - dedup scan starting.
1598 19/04/2015 22:31:05 - decrypt scan completed in 3.861 seconds.
1597 19/04/2015 22:31:02 -  ....... /media/My Video/BBC News at Ten/South Today_20150419_2222.hmt
1596 19/04/2015 22:31:02 -  ....... /media/My Video/BBC News at Ten/South Today_20150419_2222.nts
1595 19/04/2015 22:31:02 -  ....... /media/My Video/BBC News at Ten/South Today_20150419_2222.ts
1594 19/04/2015 22:31:02 - Flattening /media/My Video/BBC News at Ten/South Today_20150419_2222.ts
1593 19/04/2015 22:31:02 -   >  South Today_20150419_2222.ts
1592 19/04/2015 22:31:02 -  ....... /media/My Video/BBC News at Ten/BBC News_20150419_2159.hmt
1591 19/04/2015 22:31:02 -  ....... /media/My Video/BBC News at Ten/BBC News_20150419_2159.nts
1590 19/04/2015 22:31:02 -  ....... /media/My Video/BBC News at Ten/BBC News_20150419_2159.ts
1589 19/04/2015 22:31:02 - Flattening /media/My Video/BBC News at Ten/BBC News_20150419_2159.ts
1588 19/04/2015 22:31:02 -   >  BBC News_20150419_2159.ts
1587 19/04/2015 22:31:02 - Flatten processing /media/My Video/BBC News at Ten
1586 19/04/2015 22:31:02 - decrypt scan starting.
1585 19/04/2015 22:31:02 - Media scan starting, DLNA server status: 0
1584 19/04/2015 22:31:02 - -------------------------------------------------------
1583 19/04/2015 22:31:02 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
1582 19/04/2015 22:31:02 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
1581 19/04/2015 22:31:02 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
1580 19/04/2015 22:30:34 - Media scan completed in 0.205 seconds.
1579 19/04/2015 22:30:34 - expire scan completed in 0.011 seconds.
1578 19/04/2015 22:30:34 - mp3 scan completed in 0.011 seconds.
1577 19/04/2015 22:30:34 - mpg scan completed in 0.045 seconds.
1576 19/04/2015 22:30:34 - shrink scan completed in 0.017 seconds.
1575 19/04/2015 22:30:34 - dedup scan completed in 0.012 seconds.
1574 19/04/2015 22:30:34 - decrypt scan completed in 0.014 seconds.
1573 19/04/2015 22:30:34 - Scanning single directory '/media/My Video/BBC News at Ten'
1572 19/04/2015 22:30:34 - Media scan starting, DLNA server status: 0
1571 19/04/2015 22:30:34 - -------------------------------------------------------
1570 19/04/2015 22:30:34 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
1569 19/04/2015 22:30:34 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
1568 19/04/2015 22:30:34 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
1567 19/04/2015 22:28:54 - Media scan completed in 12.536 seconds.
1566 19/04/2015 22:28:54 - expire scan completed in 0.013 seconds.
1565 19/04/2015 22:28:54 - mp3 scan completed in 0.012 seconds.
1564 19/04/2015 22:28:53 - mpg scan completed in 0.021 seconds.
1563 19/04/2015 22:28:53 - shrink scan completed in 0.024 seconds.
1562 19/04/2015 22:28:53 - dedup scan completed in 0.063 seconds.
1561 19/04/2015 22:28:53 - decrypt scan completed in 0.058 seconds.
1560 19/04/2015 22:28:53 - Scanning single directory '/media/My Video/BBC News at Ten'
1559 19/04/2015 22:28:42 - Media scan starting, DLNA server status: 0
1558 19/04/2015 22:28:41 - -------------------------------------------------------
1557 19/04/2015 22:28:41 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
1556 19/04/2015 22:28:40 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
1555 19/04/2015 22:28:39 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
1554 19/04/2015 22:21:03 -   DLNA: http://192.168.1.64:9000/web/media/24684.TS
1553 19/04/2015 22:21:03 -   DECRYPT: /media/My Video/Vera_20150419_2003
1552 19/04/2015 22:21:03 -   /media/My Video/Vera_20150419_2003.ts - Not yet indexed, trying helper.
1551 19/04/2015 22:21:02 - decrypt scan starting.
1550 19/04/2015 22:21:02 - Media scan starting, DLNA server status: 1
1549 19/04/2015 22:21:02 - -------------------------------------------------------
1548 19/04/2015 22:21:02 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
1547 19/04/2015 22:21:02 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
1546 19/04/2015 22:21:02 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
1545 19/04/2015 22:15:32 - Media scan completed in 269.246 seconds.
1544 19/04/2015 22:15:32 - expire scan completed in 0.341 seconds.
1543 19/04/2015 22:15:31 - expire scan starting.
1542 19/04/2015 22:15:31 - mp3 scan completed in 0.287 seconds.
1541 19/04/2015 22:15:31 - mp3 scan starting.
1540 19/04/2015 22:15:31 - mpg scan completed in 0.267 seconds.
1539 19/04/2015 22:15:31 - mpg scan starting.
1538 19/04/2015 22:15:31 - shrink scan completed in 0.275 seconds.
1537 19/04/2015 22:15:30 - shrink scan starting.
1536 19/04/2015 22:15:30 - dedup scan completed in 0.298 seconds.
1535 19/04/2015 22:15:30 - dedup scan starting.
1534 19/04/2015 22:15:30 - decrypt scan completed in 267.649 seconds.
1533 19/04/2015 22:15:27 - Blocking file: BBC News_20150419_2159.hmt
1532 19/04/2015 22:15:27 - Blocking file: BBC News_20150419_2159.nts
1531 19/04/2015 22:15:27 - Blocking file: BBC News_20150419_2159.ts
1530 19/04/2015 22:15:27 - Flatten failed to remove directory
1529 19/04/2015 22:15:27 -   >  BBC News_20150419_2159.ts
1528 19/04/2015 22:15:27 - Flatten processing /media/My Video/BBC News at Ten
1527 19/04/2015 22:15:27 -  ....... /media/My Video/Vera/Vera_20150419_2003.hmt
1526 19/04/2015 22:15:27 -  ....... /media/My Video/Vera/Vera_20150419_2003.nts
1525 19/04/2015 22:15:27 -  ....... /media/My Video/Vera/Vera_20150419_2003.ts
1524 19/04/2015 22:15:27 - Flattening /media/My Video/Vera/Vera_20150419_2003.ts
1523 19/04/2015 22:15:27 -   >  Vera_20150419_2003.ts
1522 19/04/2015 22:15:27 - Flatten processing /media/My Video/Vera

Activity log

924 19/04/2015 22:30:33 - Recorded: BBC News at Ten/South Today (8 minutes - BBC ONE South)
923 19/04/2015 22:22:23 - Recorded: BBC News at Ten/BBC News (22 minutes - BBC ONE South)
922 19/04/2015 22:02:11 - Recorded: Vera/Vera (118 minutes - ITV)
921 19/04/2015 21:59:59 - Recorded: Poldark/Poldark (59 minutes - BBC ONE South)
920 19/04/2015 19:28:26 - System booted (Remote control handset).

 

[MymsMan]

I've just uploaded some updated packages which increase the amount of logging and include other changes so that flatten and sweeper can run from the post-recording run. Can you see how these work for you? If nothing else there should be clues about why it is not always working.

One oddity with the new code, repeated attempts to Flatten a recording from the [Deleted items] folder, the folder does have the noflatten flag set.

2242 20/04/2015 05:25:03 - decrypt scan completed in 1.946 seconds.
2241 20/04/2015 05:25:02 -   @ /mod/webif/lib/bin/auto:::flatten::scan:105
2240 20/04/2015 05:25:02 -   @ /mod/webif/plugin/flatten/auto.hook:::flatten::processdir:54
2239 20/04/2015 05:25:02 -   @ /mod/webif/plugin/flatten/auto.hook::34
2238 20/04/2015 05:25:02 - Plugin error: can't read "root": no such variable
2237 20/04/2015 05:25:02 -  ....... /media/My Video/[Deleted Items]/New_ CSI_ Crime Scene____20150418_2309.ts
2236 20/04/2015 05:25:02 - Flattening /media/My Video/[Deleted Items]/New_ CSI_ Crime Scene____20150418_2309.ts
2235 20/04/2015 05:25:02 -   >  New_ CSI_ Crime Scene____20150418_2309.ts
2234 20/04/2015 05:25:02 - Flatten processing /media/My Video/[Deleted Items]
2233 20/04/2015 05:25:01 - decrypt scan starting.
2232 20/04/2015 05:25:01 - Media scan starting, DLNA server status: 0

 

[af123]

Thanks. I don't use flatten myself so was only able to test it so far. I'll update the package tonight.

 

[Black Hole]

[Deleted Items] shouldn't need a .noflatten flag - the prefix "[" in the folder name should be sufficient to prevent it being flattened.

My "[" folders appear to function as expected, but I don't know what it says in the log...

Mine shows the same thing: the auto log shows an attempt to flatten a "[" folder that fails due to a plugin error reading "root". It must be bloody busy, 'cos I have quite a few [ folders! My [ folders do not have the .noflatten flag, but show the tyre icon in the WebIF media broswer. I presume the icon is triggered by either the .noflatten flag or by being [ folders.

(I like the new log browser, by the way)

 

[af123]

The fix is just to add the following line to /mod/webif/plugin/flatten/auto.hook - right near to the top of the file, indicated by the leading + below.

proc ::flatten::processdir {dir} {
+  global root
  if {[string match {\[*} $dir]} {
  log "  Special" 2
  continue
  }

 

[MymsMan]

[Deleted Items] shouldn't need a .noflatten flag - the prefix "[" in the folder name should be sufficient to prevent it being flattened.

Diverging from the topic of this thread a bit - Decrypt/Shrink/Crop when invoked from the browse panel (and possibly others) move the files to a folder named _original rather than [original] which is not immune from flattening and so I have got into the habit of setting the noflatten flag on all folders I want to keep to prevent them going AWOL.

 

[MymsMan]

The fix is just to add the following line to /mod/webif/plugin/flatten/auto.hook - right near to the top of the file, indicated by the leading + below.

More importantly the 'continue' in the first two 'if's needs to be turned into 'return' since it is now a procedure and no longer a foreach loop.

+        global root
    if {[string match {\[*} $dir]} {
        log "      Special $dir" 2
+        return
    }
    if {[file exists "$dir/.noflatten"]} {
        log "      No-flatten $dir" 2
+        return
    }

With just the Global line it suceeded in moving much of the dustbin back into the root!

Edit: More debugging needed - even with the returns it is still attempting to flatten the Dustbin

The reason it is failing to recognize Special directories is that originally the code just matched the directory name portion looking for starting [ now it is using the full directory path and so the [ is not at the start and the test is failing. For now use the noflatten option

 

[MymsMan]

Getting back to the real subject of discussion the recording of Countdown finished today at 14:59 and was immediately Flattened, similarly for 32 Brinkburn Street at 15:00
The 15:05 scheduled scan started but failed for some reason just after the start of the decrypt scan line 210
The 15:25 scheduled scan ran normally decrypting two recordings

I don't like the decrease in frequency of scheduled to 20 minutes but do like the offsetting from the hour to reduce the likelihood of end of recording scans colliding with scheduled scans, I still depend on the scheduled runs to actually do the actual decryption and scheduling of ad detection so still prefer a more frequent scan to reduce chance of long waits. I would prefer 5-59/10 or 5-59/15.

On a related theme would it be possible to initiate a run of Auto (and Detectads) at system boot to handle any processing that had not been completed because of the system shutting itself down after a scheduled recording.

233 20/04/2015 15:31:56 -   DETECTADS: Queued /media/My Video/Countdown_20150420_1409.ts for advert detection
232 20/04/2015 15:31:56 -   DETECTADS: Checking /media/My Video/Countdown_20150420_1409.ts (Channel 4) for channel exclusion
231 20/04/2015 15:31:56 - Done... 1.05 GiB in 179.54 seconds - 5.99 MiB/s
230 20/04/2015 15:31:55 -   Removing/binning old copy.
229 20/04/2015 15:30:12 - autotrigger[6208]: will run for /media/My Video/Brain of Britain
228 20/04/2015 15:28:56 -   DLNA: http://192.168.1.64:9000/web/media/24718.TS
227 20/04/2015 15:28:56 -   DECRYPT: /media/My Video/Countdown_20150420_1409
226 20/04/2015 15:28:56 -   /media/My Video/Countdown_20150420_1409.ts - Not yet indexed, trying helper.
225 20/04/2015 15:28:56 - Matched exclusion entry BBC * - skipping ad detection
224 20/04/2015 15:28:56 -   DETECTADS: Checking /media/My Video/32 Brinkburn Street_20150420_1415.ts (BBC ONE South) for channel exclusion
223 20/04/2015 15:28:56 - Done... 1.33 GiB in 231.843 seconds - 5.85 MiB/s
222 20/04/2015 15:28:55 -   Removing/binning old copy.
221 20/04/2015 15:25:04 -   DLNA: http://192.168.1.64:9000/web/media/24718.TS
220 20/04/2015 15:25:04 -   DECRYPT: /media/My Video/32 Brinkburn Street_20150420_1415
219 20/04/2015 15:25:03 -   /media/My Video/32 Brinkburn Street_20150420_1415.ts - Not yet indexed, trying helper.
218 20/04/2015 15:25:02 - decrypt scan starting.
217 20/04/2015 15:25:02 - Media scan starting, DLNA server status: 1
216 20/04/2015 15:25:02 - -------------------------------------------------------
215 20/04/2015 15:25:02 - Registered ::sweeper::scansingledir for postdecryptsingledir hook with priority 50.
214 20/04/2015 15:25:02 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
213 20/04/2015 15:25:02 - Registered ::flatten::scandir for postdecryptsingledir hook with priority 50.
212 20/04/2015 15:25:02 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
211 20/04/2015 15:25:02 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
210 20/04/2015 15:05:02 - decrypt scan starting.
209 20/04/2015 15:05:02 - Media scan starting, DLNA server status: 1
208 20/04/2015 15:05:02 - -------------------------------------------------------
207 20/04/2015 15:05:02 - Registered ::sweeper::scansingledir for postdecryptsingledir hook with priority 50.
206 20/04/2015 15:05:02 - Registered ::sweeper::scan for postdecryptscan hook with priority 50.
205 20/04/2015 15:05:02 - Registered ::flatten::scandir for postdecryptsingledir hook with priority 50.
204 20/04/2015 15:05:02 - Registered ::flatten::scan for postdecryptscan hook with priority 50.
203 20/04/2015 15:05:01 - Registered ::detectads::chancheck for postdecrypt hook with priority 30.
202 20/04/2015 15:00:41 - autotrigger[4514]: done
201 20/04/2015 15:00:40 - autotrigger[4514]: Media scan completed in 0.528 seconds.
200 20/04/2015 15:00:40 - autotrigger[4514]: expire scan completed in 0.011 seconds.
199 20/04/2015 15:00:40 - autotrigger[4514]: mp3 scan completed in 0.012 seconds.
198 20/04/2015 15:00:40 - autotrigger[4514]: mpg scan completed in 0.01 seconds.
197 20/04/2015 15:00:40 - autotrigger[4514]: shrink scan completed in 0.015 seconds.
196 20/04/2015 15:00:40 - autotrigger[4514]: dedup scan completed in 0.011 seconds.
195 20/04/2015 15:00:40 - autotrigger[4514]: decrypt scan completed in 0.31 seconds.
194 20/04/2015 15:00:40 - autotrigger[4514]:  ....... /media/My Video/32 Brinkburn Street/32 Brinkburn Street_20150420_1415.hmt
193 20/04/2015 15:00:40 - autotrigger[4514]:  ....... /media/My Video/32 Brinkburn Street/32 Brinkburn Street_20150420_1415.nts
192 20/04/2015 15:00:40 - autotrigger[4514]:  ....... /media/My Video/32 Brinkburn Street/32 Brinkburn Street_20150420_1415.ts
191 20/04/2015 15:00:40 - autotrigger[4514]: Flattening /media/My Video/32 Brinkburn Street/32 Brinkburn Street_20150420_1415.ts
190 20/04/2015 15:00:40 - autotrigger[4514]:   >  32 Brinkburn Street_20150420_1415.ts
189 20/04/2015 15:00:40 - autotrigger[4514]: Flatten processing /media/My Video/32 Brinkburn Street
188 20/04/2015 15:00:40 - autotrigger[4514]: Scanning single directory '/media/My Video/32 Brinkburn Street'
187 20/04/2015 15:00:40 - autotrigger[4514]: Media scan starting, DLNA server status: 1
186 20/04/2015 15:00:40 - autotrigger[4514]: -------------------------------------------------------
185 20/04/2015 15:00:40 - autotrigger[4514]: Registered ::sweeper::scansingledir for postdecryptsingledir hook with priority 50.
184 20/04/2015 15:00:40 - autotrigger[4514]: Registered ::sweeper::scan for postdecryptscan hook with priority 50.
183 20/04/2015 15:00:40 - autotrigger[4514]: Registered ::flatten::scandir for postdecryptsingledir hook with priority 50.
182 20/04/2015 15:00:40 - autotrigger[4514]: Registered ::flatten::scan for postdecryptscan hook with priority 50.
181 20/04/2015 15:00:40 - autotrigger[4514]: Registered ::detectads::chancheck for postdecrypt hook with priority 30.
180 20/04/2015 15:00:39 - autotrigger[4514]: got lock
179 20/04/2015 15:00:39 - autotrigger[4514]: will run for /media/My Video/32 Brinkburn Street
178 20/04/2015 14:59:04 - autotrigger[4415]: done
177 20/04/2015 14:59:04 - autotrigger[4415]: Media scan completed in 0.53 seconds.
176 20/04/2015 14:59:04 - autotrigger[4415]: expire scan completed in 0.013 seconds.
175 20/04/2015 14:59:04 - autotrigger[4415]: mp3 scan completed in 0.013 seconds.
174 20/04/2015 14:59:04 - autotrigger[4415]: mpg scan completed in 0.014 seconds.
173 20/04/2015 14:59:04 - autotrigger[4415]: shrink scan completed in 0.011 seconds.
172 20/04/2015 14:59:04 - autotrigger[4415]: dedup scan completed in 0.01 seconds.
171 20/04/2015 14:59:04 - autotrigger[4415]: decrypt scan completed in 0.309 seconds.
170 20/04/2015 14:59:04 - autotrigger[4415]:  ....... /media/My Video/Countdown/Countdown_20150420_1409.hmt
169 20/04/2015 14:59:04 - autotrigger[4415]:  ....... /media/My Video/Countdown/Countdown_20150420_1409.nts
168 20/04/2015 14:59:04 - autotrigger[4415]:  ....... /media/My Video/Countdown/Countdown_20150420_1409.ts
167 20/04/2015 14:59:04 - autotrigger[4415]: Flattening /media/My Video/Countdown/Countdown_20150420_1409.ts
166 20/04/2015 14:59:03 - autotrigger[4415]:   >  Countdown_20150420_1409.ts
165 20/04/2015 14:59:03 - autotrigger[4415]: Flatten processing /media/My Video/Countdown
164 20/04/2015 14:59:03 - autotrigger[4415]: Scanning single directory '/media/My Video/Countdown'
163 20/04/2015 14:59:03 - autotrigger[4415]: Media scan starting, DLNA server status: 1
162 20/04/2015 14:59:03 - autotrigger[4415]: -------------------------------------------------------
161 20/04/2015 14:59:03 - autotrigger[4415]: Registered ::sweeper::scansingledir for postdecryptsingledir hook with priority 50.
160 20/04/2015 14:59:03 - autotrigger[4415]: Registered ::sweeper::scan for postdecryptscan hook with priority 50.
159 20/04/2015 14:59:03 - autotrigger[4415]: Registered ::flatten::scandir for postdecryptsingledir hook with priority 50.
158 20/04/2015 14:59:03 - autotrigger[4415]: Registered ::flatten::scan for postdecryptscan hook with priority 50.
157 20/04/2015 14:59:03 - autotrigger[4415]: Registered ::detectads::chancheck for postdecrypt hook with priority 30.
156 20/04/2015 14:59:03 - autotrigger[4415]: got lock
155 20/04/2015 14:59:03 - autotrigger[4415]: will run for /media/My Video/Countdown

 

[af123]

Edit: More debugging needed - even with the returns it is still attempting to flatten the Dustbin

The reason it is failing to recognize Special directories is that originally the code just matched the directory name portion looking for starting [ now it is using the full directory path and so the [ is not at the start and the test is failing. For now use the noflatten option

Try this:

ndex: webif/plugin/flatten/auto.hook
===================================================================
--- webif/plugin/flatten/auto.hook   (revision 2404)
+++ webif/plugin/flatten/auto.hook   (working copy)
@@ -2,7 +2,7 @@
 proc ::flatten::processdir {dir} {
   global root

-   if {[string match {\[*} $dir]} {
+   if {[string match {\[*} [file tail $dir]]} {
     log "  Special" 2
     return
   }