facelets - Why sometimes there are multiple JSF life cycles invoked? -

i connected simple jsf lifecycle listener webbapp:

public class lifecyclelistener implements phaselistener  {  @override public phaseid getphaseid() {     return phaseid.any_phase; }  @override public void beforephase(phaseevent event) {     system.out.println("start phase " + event.getphaseid()); }  @override public void afterphase(phaseevent event) {     system.out.println("end phase " + event.getphaseid()); }  } 

on 1 of pages have smth this:

<h:form>   <h:commandlink id="avdertaddedtomainpage" action="#{topview.showmainpage}">       main page   </h:commandlink> </h:form> 

where topview simple bean configured in faces-config request-scoped:

public class topview {  public topview() { }  public string showaddadvert() {     return "addadvert"; }  public string showmainpage() {     return "itemlist"; }  } 

what makes me wonder that, if click above link, seems work properly, according licecyclelistener's output every phase run 2 times (yesterday count 4 times because of issue threads) before page loads up. normal behaviour? if indicates kind of bug in code, should it?

i use mojarra 2.0.2 on glassfish 3.0.1

here output today's try. there 2 rounds of lifecycle, yesterday had 4. when @ yestarday's logs discovered had more 1 thread, guess had smth modifying app while server running. still don't know if 2-rounds of lifecycle thing. note there few warnings setting character encoding don't know if matters.

fine: [web-security] policy context id was: powypadkowe/powypadkowe fine: [web-security] hasuserdatapermission perm: (javax.security.jacc.webuserdatapermission /faces/advertaddedcl.xhtml post) fine: [web-security] hasuserdatapermission isgranted: true fine: [web-security] policy context id was: powypadkowe/powypadkowe fine: [web-security] hasresource isgranted: true fine: [web-security] hasresource perm: (javax.security.jacc.webresourcepermission /faces/advertaddedcl.xhtml post) warning: pwc4011: unable set request character encoding utf-8 context /powypadkowe, because request parameters have been read, or servletrequest.getreader() has been called warning: pwc4011: unable set request character encoding utf-8 context /powypadkowe, because request parameters have been read, or servletrequest.getreader() has been called info: start phase restore_view 1 info: end phase restore_view 1 info: start phase apply_request_values 2 info: end phase apply_request_values 2 info: start phase process_validations 3 info: end phase process_validations 3 info: start phase update_model_values 4 info: end phase update_model_values 4 info: start phase invoke_application 5 info: end phase invoke_application 5 info: start phase render_response 6 info: ------- hibernate sql selects ------- info: end phase render_response 6 fine: securitycontext: setcurrentsecuritycontext method called fine: [web-security] policy context id was: powypadkowe/powypadkowe fine: [web-security] hasuserdatapermission perm: (javax.security.jacc.webuserdatapermission /faces/photos/nowy17@mail.pl/atojest/item_1/1m.jpg get) fine: [web-security] hasuserdatapermission isgranted: true fine: [web-security] policy context id was: powypadkowe/powypadkowe fine: [web-security] hasresource isgranted: true fine: [web-security] hasresource perm: (javax.security.jacc.webresourcepermission /faces/photos/nowy17@mail.pl/atojest/item_1/1m.jpg get) warning: pwc4011: unable set request character encoding utf-8 context /powypadkowe, because request parameters have been read, or servletrequest.getreader() has been called warning: pwc4011: unable set request character encoding utf-8 context /powypadkowe, because request parameters have been read, or servletrequest.getreader() has been called info: start phase restore_view 1 info: end phase restore_view 1 info: start phase apply_request_values 2 info: end phase apply_request_values 2 info: start phase process_validations 3 info: end phase process_validations 3 info: start phase update_model_values 4 info: end phase update_model_values 4 info: start phase invoke_application 5 info: end phase invoke_application 5 info: start phase render_response 6 info: end phase render_response 6 fine: securitycontext: setcurrentsecuritycontext method called 

and fragment of yestarday's log:

[#|2012-06-04t22:05:49.158+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=30;_threadname=thread-1;|end phase update_model_values 4|#]  [#|2012-06-04t22:05:49.158+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=33;_threadname=thread-1;|start phase restore_view 1|#]  [#|2012-06-04t22:05:49.161+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=31;_threadname=thread-1;|start phase render_response 6|#]  [#|2012-06-04t22:05:49.162+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=33;_threadname=thread-1;|end phase restore_view 1|#]  [#|2012-06-04t22:05:49.163+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=33;_threadname=thread-1;|start phase apply_request_values 2|#]  [#|2012-06-04t22:05:49.261+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=32;_threadname=thread-1;|start phase apply_request_values 2|#]  [#|2012-06-04t22:05:49.261+0200|info|glassfish3.0.1|javax.enterprise.system.std.com.sun.enterprise.v3.services.impl|_threadid=33;_threadname=thread-1;|end phase apply_request_values 2|#] 

i don't know if that's how it's supposed work, matches observations of happens.