Hugo: [armel/mips port] TestPageBundlerSiteRegular fails with v0.40 and v0.40.1

Created on 26 Apr 2018  路  6Comments  路  Source: gohugoio/hugo

Hugo v0.40 and v0.40.1 fails to build on armel (ARM EABI with soft float) and only on armel on Debian build daemon:

Note: The same test for mips build took over 10 minutes and go test timed out, but increasing the go test timeout value should fix it.

With the help of git bisect run on a Debian armel test machine, it was found that the first commit that causes TestPageBundlerSiteRegular to fail on armel is 4d26ab33dcef704086f43828d1dfb4b8beae2593:

(sid_armel-dchroot)foka@abel:~/go/src/github.com/gohugoio/hugo$ time go test -v -run TestPageBundlerSiteRegular ./hugolib/ 
=== RUN   TestPageBundlerSiteRegular
=== PAUSE TestPageBundlerSiteRegular
=== CONT  TestPageBundlerSiteRegular
=== RUN   TestPageBundlerSiteRegular/ugly=false
ERROR 2018/04/26 14:41:26 Resources's GetByPrefix is deprecated and will be removed in Hugo 0.42. We have added the more flexible Resources.GetMatch (find one) and Resources.Match (many) to replace the "prefix" methods. 

These matches by a given globbing pattern, e.g. "*.jpg".

Some examples:

* To find all resources by its prefix in the root dir of the bundle: .Match image*
* To find one resource by its prefix in the root dir of the bundle: .GetMatch image*
* To find all JPEG images anywhere in the bundle: .Match **.jpg
=== RUN   TestPageBundlerSiteRegular/ugly=true
--- FAIL: TestPageBundlerSiteRegular (356.79s)
    --- FAIL: TestPageBundlerSiteRegular/ugly=false (179.46s)
        Error Trace:    testhelpers_test.go:440
                        page_bundler_test.go:194
        Error:          Should be true
        Test:           TestPageBundlerSiteRegular/ugly=false
        Messages:       File no match for
                        "TheContent" in
                        "/work/public/2017/pageslug/index.html":

                        Single Title: Bundle Galore
                        Content: 


                        Sunset RelPermalink: /2017/pageslug/sunset1.jpg

                        Thumb Width: 123
                        Thumb Name: my-sunset-1
                        Thumb Title: Sunset Galore 1
                        Thumb RelPermalink: /2017/pageslug/sunset1_hu59e56ffff1bc1d8d122b1403d34e039f_90587_123x123_fill_q75_box_smart1.jpg


                        0: Image Title: c/logo.png
                        0: Image Name: c/logo.png
                        0: Image Params: map[]
                        0: Image myParam: Lower:  Caps: 

                        1: Image Title: Sunset Galore 1
                        1: Image Name: my-sunset-1
                        1: Image Params: map[myparam:My Sunny Param]
                        1: Image myParam: Lower: My Sunny Param Caps: My Sunny Param

                        2: Image Title: Sunset Galore 2
                        2: Image Name: my-sunset-2
                        2: Image Params: map[myparam:My Sunny Param]
                        2: Image myParam: Lower: My Sunny Param Caps: My Sunny Param

    --- FAIL: TestPageBundlerSiteRegular/ugly=true (177.33s)
        Error Trace:    testhelpers_test.go:440
                        page_bundler_test.go:170
        Error:          Should be true
        Test:           TestPageBundlerSiteRegular/ugly=true
        Messages:       File no match for
                        "TheContent" in
                        "/work/public/2017/pageslug.html":

                        Single Title: Bundle Galore
                        Content: 


                        Sunset RelPermalink: /2017/pageslug/sunset1.jpg

                        Thumb Width: 123
                        Thumb Name: my-sunset-1
                        Thumb Title: Sunset Galore 1
                        Thumb RelPermalink: /2017/pageslug/sunset1_hu59e56ffff1bc1d8d122b1403d34e039f_90587_123x123_fill_q75_box_smart1.jpg


                        0: Image Title: c/logo.png
                        0: Image Name: c/logo.png
                        0: Image Params: map[]
                        0: Image myParam: Lower:  Caps: 

                        1: Image Title: Sunset Galore 1
                        1: Image Name: my-sunset-1
                        1: Image Params: map[myparam:My Sunny Param]
                        1: Image myParam: Lower: My Sunny Param Caps: My Sunny Param

                        2: Image Title: Sunset Galore 2
                        2: Image Name: my-sunset-2
                        2: Image Params: map[myparam:My Sunny Param]
                        2: Image myParam: Lower: My Sunny Param Caps: My Sunny Param

FAIL
FAIL    github.com/gohugoio/hugo/hugolib    356.897s

real    6m5.887s
user    9m50.685s
sys 0m1.795s

I have no idea what is causing this, but I will try to find out soon.

picture anthonyfok

Most helpful comment

My guess it is a timing issue. There is a "timer" config parameter that is default 10 seconds (10000 milliseconds). It is there to bail out of potential circular shortcode loops, but my guess that this can be too short in some low-cpu environments when all the tests are run in parallel.

You can add a cfg.Set("timer", 30000) or something to this test to verify.

picture bep on 26 Apr 2018
❤1 👍1

All 6 comments

My guess it is a timing issue. There is a "timer" config parameter that is default 10 seconds (10000 milliseconds). It is there to bail out of potential circular shortcode loops, but my guess that this can be too short in some low-cpu environments when all the tests are run in parallel.

You can add a cfg.Set("timer", 30000) or something to this test to verify.

bep picture bep on 26 Apr 2018
❤1 👍1

My guess it is a timing issue. ... You can add a cfg.Set("timer", 30000) or something to this test to verify.

That is exactly it! Thank you so much! TestPageBundlerSiteRegular runs correctly on armel after adding ~cfg.Set("timer", 30000)~ cfg.Set("timeout", 120000) in that test.

I noticed that you have indeed written a warning in case the timeout happens:

WARNING: Timed out creating content for page %q (.Content will be empty). This is most likely a circular shortcode content loop that should be fixed. If this is just a shortcode calling a slow remote service, try to set "timeout=20000" (or higher, value is in milliseconds) in config.toml.

But that warning does not show up when I tried to run go test -v -run TestPageBundlerSiteRegular/ugly=false ./hugolib, even after I tried adding cfg.Set("verbose", true) and cfg.Set("debug", true). Was I doing it the wrong way? Or are there ways to expose these warnings during the test? Many thanks!

anthonyfok picture anthonyfok on 26 Apr 2018

Or are there ways to expose these warnings during the test? Many thanks!

We should improve on this, but,something ala:

s := buildSingleSite(t, deps.DepsCfg{Logger: newWarningLogger(), Fs: fs, Cfg: cfg}, BuildCfg{})

It is default on ERROR level ... I hate to look at chatty logs when I develop.

bep picture bep on 26 Apr 2018
❤1

As to the reason why that test takes time, is probably because of some image processing ...

bep picture bep on 26 Apr 2018

As to the reason why that test takes time, is probably because of some image processing ...

Indeed, soft float can be really slow, and according to this https://www.raspberrypi.org/forums/viewtopic.php?t=49970, soft float can be ~100 times slower than hard float. Yikes!

anthonyfok picture anthonyfok on 26 Apr 2018

Yay! https://buildd.debian.org/status/package.php?p=hugo is all green again in Hugo 0.40.1-3!

Here is the actual patch that went into the Debian package:

https://salsa.debian.org/go-team/packages/hugo/blob/master/debian/patches/004-increase-timeout-in-TestPageBundlerSiteRegular.patch

Special thanks to @ bep for providing the solution!

anthonyfok picture anthonyfok on 27 Apr 2018
Was this page helpful?
0 / 5 - 0 ratings

Related issues

nikolas picture nikolas  路  3Comments
tjamet picture tjamet  路  3Comments
VoidingWarranties picture VoidingWarranties  路  3Comments
chrissparksnj picture chrissparksnj  路  3Comments
kaushalmodi picture kaushalmodi  路  3Comments